mirror of https://github.com/mitsuhiko/flask.git
Browse Source
single default handler and formatter don't remove handlers configure level once using setLevel document logging reorganize logging testspull/2436/head
David Lord
7 years ago
13 changed files with 404 additions and 456 deletions
@ -0,0 +1,175 @@ |
|||||||
|
.. _logging: |
||||||
|
|
||||||
|
Logging |
||||||
|
======= |
||||||
|
|
||||||
|
Flask uses standard Python :mod:`logging`. All Flask-related messages are |
||||||
|
logged under the ``'flask'`` logger namespace. |
||||||
|
:meth:`Flask.logger <flask.Flask.logger>` returns the logger named |
||||||
|
``'flask.app'``, and can be used to log messages for your application. :: |
||||||
|
|
||||||
|
@app.route('/login', methods=['POST']) |
||||||
|
def login(): |
||||||
|
user = get_user(request.form['username']) |
||||||
|
|
||||||
|
if user.check_password(request.form['password']): |
||||||
|
login_user(user) |
||||||
|
app.logger.info('%s logged in successfully', user.username) |
||||||
|
return redirect(url_for('index')) |
||||||
|
else: |
||||||
|
app.logger.info('%s failed to log in', user.username) |
||||||
|
abort(401) |
||||||
|
|
||||||
|
|
||||||
|
Basic Configuration |
||||||
|
------------------- |
||||||
|
|
||||||
|
When you want to configure logging for your project, you should do it as soon |
||||||
|
as possible when the program starts. If :meth:`app.logger <flask.Flask.logger>` |
||||||
|
is accessed before logging is configured, it will add a default handler. If |
||||||
|
possible, configure logging before creating the application object. |
||||||
|
|
||||||
|
This example uses :func:`~logging.config.dictConfig` to create a logging |
||||||
|
configuration similar to Flask's default, except for all logs:: |
||||||
|
|
||||||
|
from logging.config import dictConfig |
||||||
|
|
||||||
|
dictConfig({ |
||||||
|
'version': 1, |
||||||
|
'formatters': {'default': { |
||||||
|
'format': '[%(asctime)s] %(levelname)s in %(module)s: %(message)s', |
||||||
|
}}, |
||||||
|
'handlers': {'wsgi': { |
||||||
|
'class': 'logging.StreamHandler', |
||||||
|
'stream': 'ext://flask.logging.wsgi_errors_stream', |
||||||
|
'formatter': 'default' |
||||||
|
}}, |
||||||
|
'root': { |
||||||
|
'level': 'INFO', |
||||||
|
'handlers': ['wsgi'] |
||||||
|
} |
||||||
|
}) |
||||||
|
|
||||||
|
app = Flask(__name__) |
||||||
|
|
||||||
|
|
||||||
|
Default Configuration |
||||||
|
````````````````````` |
||||||
|
|
||||||
|
If you do not configure logging yourself, Flask will add a |
||||||
|
:class:`~logging.StreamHandler` to :meth:`app.logger <flask.Flask.logger>` |
||||||
|
automatically. During requests, it will write to the stream specified by the |
||||||
|
WSGI server in ``environ['wsgi.errors']`` (which is usually |
||||||
|
:data:`sys.stderr`). Outside a request, it will log to :data:`sys.stderr`. |
||||||
|
|
||||||
|
|
||||||
|
Removing the Default Handler |
||||||
|
```````````````````````````` |
||||||
|
|
||||||
|
If you configured logging after accessing |
||||||
|
:meth:`app.logger <flask.Flask.logger>`, and need to remove the default |
||||||
|
handler, you can import and remove it:: |
||||||
|
|
||||||
|
from flask.logging import default_handler |
||||||
|
|
||||||
|
app.logger.removeHandler(default_handler) |
||||||
|
|
||||||
|
|
||||||
|
Email Errors to Admins |
||||||
|
---------------------- |
||||||
|
|
||||||
|
When running the application on a remote server for production, you probably |
||||||
|
won't be looking at the log messages very often. The WSGI server will probably |
||||||
|
send log messages to a file, and you'll only check that file if a user tells |
||||||
|
you something went wrong. |
||||||
|
|
||||||
|
To be proactive about discovering and fixing bugs, you can configure a |
||||||
|
:class:`logging.handlers.SMTPHandler` to send an email when errors and higher |
||||||
|
are logged. :: |
||||||
|
|
||||||
|
import logging |
||||||
|
from logging.handlers import SMTPHandler |
||||||
|
|
||||||
|
mail_handler = SMTPHandler( |
||||||
|
mailhost='127.0.0.1', |
||||||
|
fromaddr='server-error@example.com', |
||||||
|
toaddrs=['admin@example.com'], |
||||||
|
subject='Application Error' |
||||||
|
) |
||||||
|
mail_handler.setLevel(logging.ERROR) |
||||||
|
mail_handler.setFormatter(logging.Formatter( |
||||||
|
'[%(asctime)s] %(levelname)s in %(module)s: %(message)s' |
||||||
|
)) |
||||||
|
|
||||||
|
if not app.debug: |
||||||
|
app.logger.addHandler(mail_handler) |
||||||
|
|
||||||
|
This requires that you have an SMTP server set up on the same server. See the |
||||||
|
Python docs for more information about configuring the handler. |
||||||
|
|
||||||
|
|
||||||
|
Injecting Request Information |
||||||
|
----------------------------- |
||||||
|
|
||||||
|
Seeing more information about the request, such as the IP address, may help |
||||||
|
debugging some errors. You can subclass :class:`logging.Formatter` to inject |
||||||
|
your own fields that can be used in messages. You can change the formatter for |
||||||
|
Flask's default handler, the mail handler defined above, or any other |
||||||
|
handler. :: |
||||||
|
|
||||||
|
from flask import request |
||||||
|
from flask.logging import default_handler |
||||||
|
|
||||||
|
class RequestFormatter(logging.Formatter): |
||||||
|
def format(self, record): |
||||||
|
record.url = request.url |
||||||
|
record.remote_addr = request.remote_addr |
||||||
|
return super().format(record) |
||||||
|
|
||||||
|
formatter = RequestFormatter( |
||||||
|
'[%(asctime)s] %(remote_addr)s requested %(url)s\n' |
||||||
|
'%(levelname)s in %(module)s: %(message)s' |
||||||
|
)) |
||||||
|
default_handler.setFormatter(formatter) |
||||||
|
mail_handler.setFormatter(formatter) |
||||||
|
|
||||||
|
|
||||||
|
Other Libraries |
||||||
|
--------------- |
||||||
|
|
||||||
|
Other libraries may use logging extensively, and you want to see relevant |
||||||
|
messages from those logs too. The simplest way to do this is to add handlers |
||||||
|
to the root logger instead of only the app logger. :: |
||||||
|
|
||||||
|
from flask.logging import default_handler |
||||||
|
|
||||||
|
root = logging.getLogger() |
||||||
|
root.addHandler(default_handler) |
||||||
|
root.addHandler(mail_handler) |
||||||
|
|
||||||
|
Depending on your project, it may be more useful to configure each logger you |
||||||
|
care about separately, instead of configuring only the root logger. :: |
||||||
|
|
||||||
|
for logger in ( |
||||||
|
app.logger, |
||||||
|
logging.getLogger('sqlalchemy'), |
||||||
|
logging.getLogger('other_package'), |
||||||
|
): |
||||||
|
logger.addHandler(default_handler) |
||||||
|
logger.addHandler(mail_handler) |
||||||
|
|
||||||
|
|
||||||
|
Werkzeug |
||||||
|
```````` |
||||||
|
|
||||||
|
Werkzeug logs basic request/response information to the ``'werkzeug'`` logger. |
||||||
|
If the root logger has no handlers configured, Werkzeug adds a |
||||||
|
:class:`~logging.StreamHandler` to its logger. |
||||||
|
|
||||||
|
|
||||||
|
Flask Extensions |
||||||
|
```````````````` |
||||||
|
|
||||||
|
Depending on the situation, an extension may choose to log to |
||||||
|
:meth:`app.logger <flask.Flask.logger>` or its own named logger. Consult each |
||||||
|
extension's documentation for details. |
||||||
@ -1,94 +1,69 @@ |
|||||||
# -*- coding: utf-8 -*- |
|
||||||
""" |
|
||||||
flask.logging |
|
||||||
~~~~~~~~~~~~~ |
|
||||||
|
|
||||||
Implements the logging support for Flask. |
|
||||||
|
|
||||||
:copyright: (c) 2015 by Armin Ronacher. |
|
||||||
:license: BSD, see LICENSE for more details. |
|
||||||
""" |
|
||||||
|
|
||||||
from __future__ import absolute_import |
from __future__ import absolute_import |
||||||
|
|
||||||
|
import logging |
||||||
import sys |
import sys |
||||||
|
|
||||||
from werkzeug.local import LocalProxy |
from werkzeug.local import LocalProxy |
||||||
from logging import getLogger, StreamHandler, Formatter, getLoggerClass, \ |
|
||||||
DEBUG, ERROR |
|
||||||
from .globals import _request_ctx_stack |
|
||||||
|
|
||||||
|
|
||||||
PROD_LOG_FORMAT = '[%(asctime)s] %(levelname)s in %(module)s: %(message)s' |
from .globals import request |
||||||
DEBUG_LOG_FORMAT = ( |
|
||||||
'-' * 80 + '\n' + |
|
||||||
'%(levelname)s in %(module)s [%(pathname)s:%(lineno)d]:\n' + |
|
||||||
'%(message)s\n' + |
|
||||||
'-' * 80 |
|
||||||
) |
|
||||||
|
|
||||||
|
|
||||||
@LocalProxy |
@LocalProxy |
||||||
def _proxy_stream(): |
def wsgi_errors_stream(): |
||||||
"""Finds the most appropriate error stream for the application. If a |
"""Find the most appropriate error stream for the application. If a request |
||||||
WSGI request is in flight we log to wsgi.errors, otherwise this resolves |
is active, log to ``wsgi.errors``, otherwise use ``sys.stderr``. |
||||||
to sys.stderr. |
|
||||||
|
If you configure your own :class:`logging.StreamHandler`, you may want to |
||||||
|
use this for the stream. If you are using file or dict configuration and |
||||||
|
can't import this directly, you can refer to it as |
||||||
|
``ext://flask.logging.wsgi_errors_stream``. |
||||||
""" |
""" |
||||||
ctx = _request_ctx_stack.top |
return request.environ['wsgi.errors'] if request else sys.stderr |
||||||
if ctx is not None: |
|
||||||
return ctx.request.environ['wsgi.errors'] |
|
||||||
return sys.stderr |
def has_level_handler(logger): |
||||||
|
"""Check if there is a handler in the logging chain that will handle the |
||||||
|
given logger's :meth:`effective level <~logging.Logger.getEffectiveLevel>`. |
||||||
|
""" |
||||||
|
level = logger.getEffectiveLevel() |
||||||
|
current = logger |
||||||
|
|
||||||
|
while current: |
||||||
|
if any(handler.level <= level for handler in current.handlers): |
||||||
|
return True |
||||||
|
|
||||||
|
if not current.propagate: |
||||||
|
break |
||||||
|
|
||||||
|
current = current.parent |
||||||
|
|
||||||
def _should_log_for(app, mode): |
|
||||||
policy = app.config['LOGGER_HANDLER_POLICY'] |
|
||||||
if policy == mode or policy == 'always': |
|
||||||
return True |
|
||||||
return False |
return False |
||||||
|
|
||||||
|
|
||||||
|
#: Log messages to :func:`~flask.logging.wsgi_errors_stream` with the format |
||||||
|
#: ``[%(asctime)s] %(levelname)s in %(module)s: %(message)s``. |
||||||
|
default_handler = logging.StreamHandler(wsgi_errors_stream) |
||||||
|
default_handler.setFormatter(logging.Formatter( |
||||||
|
'[%(asctime)s] %(levelname)s in %(module)s: %(message)s' |
||||||
|
)) |
||||||
|
|
||||||
|
|
||||||
def create_logger(app): |
def create_logger(app): |
||||||
"""Creates a logger for the given application. This logger works |
"""Get the ``'flask.app'`` logger and configure it if needed. |
||||||
similar to a regular Python logger but changes the effective logging |
|
||||||
level based on the application's debug flag. Furthermore this |
When :attr:`~flask.Flask.debug` is enabled, set the logger level to |
||||||
function also removes all attached handlers in case there was a |
:data:`logging.DEBUG` if it is not set. |
||||||
logger with the log name before. |
|
||||||
|
If there is no handler for the logger's effective level, add a |
||||||
|
:class:`~logging.StreamHandler` for |
||||||
|
:func:`~flask.logging.wsgi_errors_stream` with a basic format. |
||||||
""" |
""" |
||||||
Logger = getLoggerClass() |
logger = logging.getLogger('flask.app') |
||||||
|
|
||||||
class DebugLogger(Logger): |
if app.debug and logger.level == logging.NOTSET: |
||||||
def getEffectiveLevel(self): |
logger.setLevel(logging.DEBUG) |
||||||
if self.level == 0 and app.debug: |
|
||||||
return DEBUG |
if not has_level_handler(logger): |
||||||
return Logger.getEffectiveLevel(self) |
logger.addHandler(default_handler) |
||||||
|
|
||||||
class DebugHandler(StreamHandler): |
|
||||||
def emit(self, record): |
|
||||||
if app.debug and _should_log_for(app, 'debug'): |
|
||||||
StreamHandler.emit(self, record) |
|
||||||
|
|
||||||
class ProductionHandler(StreamHandler): |
|
||||||
def emit(self, record): |
|
||||||
if not app.debug and _should_log_for(app, 'production'): |
|
||||||
StreamHandler.emit(self, record) |
|
||||||
|
|
||||||
debug_handler = DebugHandler() |
|
||||||
debug_handler.setLevel(DEBUG) |
|
||||||
debug_handler.setFormatter(Formatter(DEBUG_LOG_FORMAT)) |
|
||||||
|
|
||||||
prod_handler = ProductionHandler(_proxy_stream) |
|
||||||
prod_handler.setLevel(ERROR) |
|
||||||
prod_handler.setFormatter(Formatter(PROD_LOG_FORMAT)) |
|
||||||
|
|
||||||
logger = getLogger(app.logger_name) |
|
||||||
# just in case that was not a new logger, get rid of all the handlers |
|
||||||
# already attached to it. |
|
||||||
del logger.handlers[:] |
|
||||||
logger.__class__ = DebugLogger |
|
||||||
logger.addHandler(debug_handler) |
|
||||||
logger.addHandler(prod_handler) |
|
||||||
|
|
||||||
# Disable propagation by default |
|
||||||
logger.propagate = False |
|
||||||
|
|
||||||
return logger |
return logger |
||||||
|
|||||||
@ -0,0 +1,91 @@ |
|||||||
|
import logging |
||||||
|
import sys |
||||||
|
|
||||||
|
import pytest |
||||||
|
|
||||||
|
from flask._compat import StringIO |
||||||
|
from flask.logging import default_handler, has_level_handler, \ |
||||||
|
wsgi_errors_stream |
||||||
|
|
||||||
|
|
||||||
|
@pytest.fixture(autouse=True) |
||||||
|
def reset_logging(monkeypatch): |
||||||
|
root_handlers = logging.root.handlers[:] |
||||||
|
root_level = logging.root.level |
||||||
|
|
||||||
|
logger = logging.getLogger('flask.app') |
||||||
|
logger.handlers = [] |
||||||
|
logger.setLevel(logging.NOTSET) |
||||||
|
|
||||||
|
yield |
||||||
|
|
||||||
|
logging.root.handlers[:] = root_handlers |
||||||
|
logging.root.setLevel(root_level) |
||||||
|
|
||||||
|
logger.handlers = [] |
||||||
|
logger.setLevel(logging.NOTSET) |
||||||
|
|
||||||
|
|
||||||
|
def test_logger(app): |
||||||
|
assert app.logger.name == 'flask.app' |
||||||
|
assert app.logger.level == logging.NOTSET |
||||||
|
assert app.logger.handlers == [default_handler] |
||||||
|
|
||||||
|
|
||||||
|
def test_logger_debug(app): |
||||||
|
app.debug = True |
||||||
|
assert app.logger.level == logging.DEBUG |
||||||
|
assert app.logger.handlers == [default_handler] |
||||||
|
|
||||||
|
|
||||||
|
def test_existing_handler(app): |
||||||
|
logging.root.addHandler(logging.StreamHandler()) |
||||||
|
assert app.logger.level == logging.NOTSET |
||||||
|
assert not app.logger.handlers |
||||||
|
|
||||||
|
|
||||||
|
def test_wsgi_errors_stream(app, client): |
||||||
|
@app.route('/') |
||||||
|
def index(): |
||||||
|
app.logger.error('test') |
||||||
|
return '' |
||||||
|
|
||||||
|
stream = StringIO() |
||||||
|
client.get('/', errors_stream=stream) |
||||||
|
assert 'ERROR in test_logging: test' in stream.getvalue() |
||||||
|
|
||||||
|
assert wsgi_errors_stream._get_current_object() is sys.stderr |
||||||
|
|
||||||
|
with app.test_request_context(errors_stream=stream): |
||||||
|
assert wsgi_errors_stream._get_current_object() is stream |
||||||
|
|
||||||
|
|
||||||
|
def test_has_level_handler(): |
||||||
|
logger = logging.getLogger('flask.app') |
||||||
|
assert not has_level_handler(logger) |
||||||
|
|
||||||
|
handler = logging.StreamHandler() |
||||||
|
logging.root.addHandler(handler) |
||||||
|
assert has_level_handler(logger) |
||||||
|
|
||||||
|
logger.propagate = False |
||||||
|
assert not has_level_handler(logger) |
||||||
|
logger.propagate = True |
||||||
|
|
||||||
|
handler.setLevel(logging.ERROR) |
||||||
|
assert not has_level_handler(logger) |
||||||
|
|
||||||
|
|
||||||
|
def test_log_view_exception(app, client): |
||||||
|
@app.route('/') |
||||||
|
def index(): |
||||||
|
raise Exception('test') |
||||||
|
|
||||||
|
app.testing = False |
||||||
|
stream = StringIO() |
||||||
|
rv = client.get('/', errors_stream=stream) |
||||||
|
assert rv.status_code == 500 |
||||||
|
assert rv.data |
||||||
|
err = stream.getvalue() |
||||||
|
assert 'Exception on / [GET]' in err |
||||||
|
assert 'Exception: test' in err |
||||||
Loading…
Reference in new issue