forked from orbit-oss/flask
Added a documentation chapter about logging
This commit is contained in:
parent
e7f67e1333
commit
ea5e654e9e
9 changed files with 307 additions and 11 deletions
5
docs/_templates/sidebarintro.html
vendored
5
docs/_templates/sidebarintro.html
vendored
|
|
@ -5,7 +5,10 @@
|
|||
not stable yet, but if you have some feedback,
|
||||
<a href="mailto:armin.ronacher@active-4.com">let me know</a>.
|
||||
</p>
|
||||
<h3>Download Documentation</h3>
|
||||
<h3>Other Formats</h3>
|
||||
<p>
|
||||
You can download the documentation in other formats as well:
|
||||
</p>
|
||||
<ul>
|
||||
<li><a href="http://flask.pocoo.org/docs/flask-docs.pdf">as PDF</a>
|
||||
<li><a href="http://flask.pocoo.org/docs/flask-docs.zip">as zipped HTML</a>
|
||||
|
|
|
|||
|
|
@ -1 +1 @@
|
|||
Subproject commit 11cb6b51c9ea3bc8f94afa3d7411b617f9db2570
|
||||
Subproject commit 991997d6d63a0cdcf7f4557a2dae5afa9b38b904
|
||||
|
|
@ -50,6 +50,8 @@ import pkg_resources
|
|||
# built documents.
|
||||
release = __import__('pkg_resources').get_distribution('Flask').version
|
||||
version = '.'.join(release.split('.')[:2])
|
||||
if 'dev' in version:
|
||||
version = version.split('dev')[0]
|
||||
|
||||
# The language for content autogenerated by Sphinx. Refer to documentation
|
||||
# for a list of supported languages.
|
||||
|
|
|
|||
|
|
@ -13,6 +13,7 @@ web development.
|
|||
quickstart
|
||||
tutorial/index
|
||||
testing
|
||||
errorhandling
|
||||
patterns/index
|
||||
deploying/index
|
||||
becomingbig
|
||||
|
|
|
|||
232
docs/errorhandling.rst
Normal file
232
docs/errorhandling.rst
Normal file
|
|
@ -0,0 +1,232 @@
|
|||
Handling Application Errors
|
||||
===========================
|
||||
|
||||
.. versionadded:: 0.5
|
||||
|
||||
Applications fail, server fail. Sooner or later you will see an exception
|
||||
in production. Even if your code is 100% correct, you will still see
|
||||
exceptions from time to time. Why? Because everything else involved will
|
||||
fail. Here some situations where perfectly fine code can lead to server
|
||||
errors:
|
||||
|
||||
- the client terminated the request early and the application was still
|
||||
reading from the incoming data.
|
||||
- the database server was overloaded and could not handle the query.
|
||||
- a filesystem is full
|
||||
- a harddrive crashed
|
||||
- a backend server overloaded
|
||||
- a programming error in a library you are using
|
||||
- network connection of the server to another system failed.
|
||||
|
||||
And that's just a small sample of issues you could be facing. So how to
|
||||
deal with that sort of problem? By default if your application runs in
|
||||
production mode, Flask will display a very simple page for you and log the
|
||||
exception to the :attr:`~flask.Flask.logger`.
|
||||
|
||||
But there is more you can do, and we will cover some better setups to deal
|
||||
with errors.
|
||||
|
||||
Error Mails
|
||||
-----------
|
||||
|
||||
If the application runs in production mode (which it will do on your
|
||||
server) you won't see any log messages by default. Why that? Flask tries
|
||||
to be a zero-configuration framework and where should it drop the logs for
|
||||
you if there is no configuration. Guessing is not a good idea because
|
||||
changes are, the place it guessed is not the place where the user has the
|
||||
permission to create a logfile. Also, for most small applications nobody
|
||||
will look at the logs anyways.
|
||||
|
||||
In fact, I promise you right now that if you configure a logfile for the
|
||||
application errors you will never look at it except for debugging an issue
|
||||
when a user reported it for you. What you want instead is a mail the
|
||||
second the exception happened. Then you get an alert and you can do
|
||||
something about it.
|
||||
|
||||
Flask is using the Python builtin logging system and that one can actually
|
||||
send you mails for errors which is probably what you want. Here is how
|
||||
you can configure the Flask logger to send you mails for exceptions::
|
||||
|
||||
ADMINS = ['yourname@example.com']
|
||||
if not app.debug:
|
||||
import logging
|
||||
from logging.handlers import SMTPHandler
|
||||
mail_handler = SMTPHandler('127.0.0.1',
|
||||
'server-error@example.com',
|
||||
ADMINS, 'YourApplication Failed')
|
||||
mail_handler.setLevel(logging.ERROR)
|
||||
app.logger.addHandler(mail_handler)
|
||||
|
||||
So what just happened? We created a new
|
||||
:class:`~logging.handlers.SMTPHandler` that will send mails with the mail
|
||||
server listening on ``127.0.0.1`` to all the `ADMINS` from the address
|
||||
*server-error@example.com* with the subject "YourApplication Failed". If
|
||||
your mail server requires credentials these can also provided, for that
|
||||
check out the documentation for the :class:`~logging.handlers.SMTPHandler`.
|
||||
|
||||
We also tell the handler to only send errors and more critical messages.
|
||||
Because we certainly don't want to get a mail for warnings or other
|
||||
useless logs that might happen during request handling.
|
||||
|
||||
Before you run that in production, please also look at :ref:`log-format`
|
||||
to put more information into that error mail. That will save you from a
|
||||
lot of frustration.
|
||||
|
||||
|
||||
Logging to a File
|
||||
-----------------
|
||||
|
||||
Even if you get mails, you probably also want to log warnings. It's a
|
||||
good idea to keep as much information around that might be required to
|
||||
debug a problem. Please note that Flask itself will not issue any
|
||||
warnings in the core system, so it's your responsibility to warn in the
|
||||
code if something seems odd.
|
||||
|
||||
There are a couple of handlers provided by the logging system out of the
|
||||
box but not all of them are useful for basic error logging. The most
|
||||
interesting are probably the following:
|
||||
|
||||
- :class:`~logging.handlers.FileHandler` - logs messages to a file on the
|
||||
filesystem.
|
||||
- :class:`~logging.handlers.RotatingFileHandler` - logs messages to a file
|
||||
on the filesystem and will rotate after a certain number of messages.
|
||||
- :class:`~logging.handlers.NTEventLogHandler` - will log to the system
|
||||
event log of a Windows system. If you are deploying on a Windows box,
|
||||
this is what you want to use.
|
||||
- :class:`~logging.handlers.SysLogHandler` - sends logs to a UNIX
|
||||
syslog.
|
||||
|
||||
Once you picked your log handler, do like you did with the SMTP handler
|
||||
above, just make sure to use a lower setting (I would recommend
|
||||
`WARNING`)::
|
||||
|
||||
if not app.debug:
|
||||
import logging
|
||||
from logging.handlers import TheHandlerYouWant
|
||||
file_handler = TheHandlerYouWant(...)
|
||||
file_handler.setLevel(logging.WARNING)
|
||||
app.logger.addHandler(file_handler)
|
||||
|
||||
.. _log-format:
|
||||
|
||||
Controlling the Log Format
|
||||
--------------------------
|
||||
|
||||
By default a handler will only write the message string into a file or
|
||||
send you that message as mail. But a log record stores more information
|
||||
and it makes a lot of sense to configure your logger to also contain that
|
||||
information so that you have a better idea of why that error happened, and
|
||||
more importantly, where it did.
|
||||
|
||||
A formatter can be instanciated with a format string. Note that
|
||||
tracebacks are appended to the log entry automatically. You don't have to
|
||||
do that in the log formatter format string.
|
||||
|
||||
Here some example setups:
|
||||
|
||||
Email
|
||||
`````
|
||||
|
||||
::
|
||||
|
||||
from logging import Formatter
|
||||
mail_handler.setFormatter(Formatter('''
|
||||
Message type: %(levelname)s
|
||||
Location: %(pathname)s:%(lineno)d
|
||||
Module: %(module)s
|
||||
Function: %(funcName)s
|
||||
Time: %(asctime)s
|
||||
|
||||
Message:
|
||||
|
||||
%(message)s
|
||||
'''))
|
||||
|
||||
File logging
|
||||
````````````
|
||||
|
||||
::
|
||||
|
||||
from logging import Formatter
|
||||
file_handler.setFormatter(Formatter(
|
||||
'%(astime)s %(levelname)s: %(message)s '
|
||||
'[in %(pathname)s:%(lineno)d]'
|
||||
))
|
||||
|
||||
|
||||
Complex Log Formatting
|
||||
``````````````````````
|
||||
|
||||
Here is a list of useful formatting variables for the format string. Note
|
||||
that this list is not complete, consult the official documentation of the
|
||||
:mod:`logging` package for a full list.
|
||||
|
||||
+------------------+----------------------------------------------------+
|
||||
| Format | Description |
|
||||
+==================+====================================================+
|
||||
| ``%(levelname)s``| Text logging level for the message |
|
||||
| | (``'DEBUG'``, ``'INFO'``, ``'WARNING'``, |
|
||||
| | ``'ERROR'``, ``'CRITICAL'``). |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(pathname)s`` | Full pathname of the source file where the |
|
||||
| | logging call was issued (if available). |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(filename)s`` | Filename portion of pathname. |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(module)s`` | Module (name portion of filename). |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(funcName)s`` | Name of function containing the logging call. |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(lineno)d`` | Source line number where the logging call was |
|
||||
| | issued (if available). |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(asctime)s`` | Human-readable time when the LogRecord` was |
|
||||
| | created. By default this is of the form |
|
||||
| | ``"2003-07-08 16:49:45,896"`` (the numbers after |
|
||||
| | the comma are millisecond portion of the time). |
|
||||
| | This can be changed by subclassing the formatter |
|
||||
| | and overriding the |
|
||||
| | :meth:`~logging.Formatter.formatTime` method. |
|
||||
+------------------+----------------------------------------------------+
|
||||
| ``%(message)s`` | The logged message, computed as ``msg % args`` |
|
||||
+------------------+----------------------------------------------------+
|
||||
|
||||
If you want to further customize the formatting, you can subclass the
|
||||
formatter. The formatter has three interesting methods:
|
||||
|
||||
:meth:`~logging.Formatter.format`:
|
||||
handles the actual formatting. It is passed a
|
||||
:class:`~logging.LogRecord` object and has to return the formatted
|
||||
string.
|
||||
:meth:`~logging.Formatter.formatTime`:
|
||||
called for `asctime` formatting. If you want a different time format
|
||||
you can override this method.
|
||||
:meth:`~logging.Formatter.formatException`
|
||||
called for exception formatting. It is passed a :attr:`~sys.exc_info`
|
||||
tuple and has to return a string. The default is usually fine, you
|
||||
don't have to override it.
|
||||
|
||||
For more information, head over to the official documentation.
|
||||
|
||||
|
||||
Other Libraries
|
||||
---------------
|
||||
|
||||
So far we only configured the logger your application created itself.
|
||||
Other libraries might log themselves as well. For example, SQLAlchemy use
|
||||
logging heavily in the core. While there is a method to configure all
|
||||
loggers at once in the :mod:`logging` package, I would not recommend using
|
||||
it. There might be a situation in which you want to have multiple
|
||||
separate applications running side by side in the same Python interpreter
|
||||
and then it becomes impossible to have different logging setups for those.
|
||||
|
||||
Instead, I would recommend figuring out which loggers you are interested
|
||||
in, getting the loggers with the :func:`~logging.getLogger` function and
|
||||
iterating over them to attach handlers::
|
||||
|
||||
from logging import getLogger
|
||||
loggers = [app.logger, getLogger('sqlalchemy'),
|
||||
getLogger('otherlibrary')]
|
||||
for logger in loggers:
|
||||
logger.addHandler(mail_handler)
|
||||
logger.addHandler(file_handler)
|
||||
|
|
@ -1,3 +1,5 @@
|
|||
.. _uploading-files:
|
||||
|
||||
Uploading Files
|
||||
===============
|
||||
|
||||
|
|
|
|||
|
|
@ -532,6 +532,8 @@ Werkzeug provides for you::
|
|||
f.save('/var/www/uploads/' + secure_filename(f.filename))
|
||||
...
|
||||
|
||||
For some better examples, checkout the :ref:`uploading-files` pattern.
|
||||
|
||||
Cookies
|
||||
```````
|
||||
|
||||
|
|
@ -639,3 +641,29 @@ To flash a message use the :func:`~flask.flash` method, to get hold of the
|
|||
messages you can use :func:`~flask.get_flashed_messages` which is also
|
||||
available in the templates. Check out the :ref:`message-flashing-pattern`
|
||||
for a full example.
|
||||
|
||||
Logging
|
||||
-------
|
||||
|
||||
.. versionadded:: 0.5
|
||||
|
||||
Sometimes you might be in the situation where you deal with data that
|
||||
should be correct, but actually is not. For example you have some client
|
||||
side code that sends an HTTP request to the server, and it's obviously
|
||||
malformed. This might be caused by a user tempering with the data, or the
|
||||
client code failed. Most the time, it's okay to reply with ``400 Bad
|
||||
Request`` in that situation, but other times it is not and the code has to
|
||||
continue working.
|
||||
|
||||
Yet you want to log that something fishy happened. This is where loggers
|
||||
come in handy. As of Flask 0.5 a logger is preconfigured for you to use.
|
||||
|
||||
Here are some example log calls::
|
||||
|
||||
app.logger.debug('A value for debugging')
|
||||
app.logger.warning('A warning ocurred (%d apples)', 42)
|
||||
app.logger.error('An error occoured')
|
||||
|
||||
The attached :attr:`~flask.Flask.logger` is a standard logging
|
||||
:class:`~logging.Logger`, so head over to the official stdlib
|
||||
documentation for more information.
|
||||
|
|
|
|||
24
flask.py
24
flask.py
|
|
@ -666,7 +666,7 @@ class Flask(_PackageBoundObject):
|
|||
#: .. versionadded:: 0.5
|
||||
debug_log_format = (
|
||||
'-' * 80 + '\n' +
|
||||
'%(levelname)s in %(module)s, %(filename)s:%(lineno)d]:\n' +
|
||||
'%(levelname)s in %(module)s, %(pathname)s:%(lineno)d]:\n' +
|
||||
'%(message)s\n' +
|
||||
'-' * 80
|
||||
)
|
||||
|
|
@ -769,7 +769,12 @@ class Flask(_PackageBoundObject):
|
|||
def logger(self):
|
||||
"""A :class:`logging.Logger` object for this application. The
|
||||
default configuration is to log to stderr if the application is
|
||||
in debug mode.
|
||||
in debug mode. This logger can be used to (surprise) log messages.
|
||||
Here some examples::
|
||||
|
||||
app.logger.debug('A value for debugging')
|
||||
app.logger.warning('A warning ocurred (%d apples)', 42)
|
||||
app.logger.error('An error occoured')
|
||||
"""
|
||||
from logging import getLogger, StreamHandler, Formatter, DEBUG
|
||||
class DebugHandler(StreamHandler):
|
||||
|
|
@ -1085,8 +1090,6 @@ class Flask(_PackageBoundObject):
|
|||
return self.view_functions[req.endpoint](**req.view_args)
|
||||
except HTTPException, e:
|
||||
return self.handle_http_exception(e)
|
||||
except Exception, e:
|
||||
return self.handle_exception(e)
|
||||
|
||||
def make_response(self, rv):
|
||||
"""Converts the return value from a view function to a real
|
||||
|
|
@ -1176,11 +1179,14 @@ class Flask(_PackageBoundObject):
|
|||
exception context to start the response
|
||||
"""
|
||||
with self.request_context(environ):
|
||||
rv = self.preprocess_request()
|
||||
if rv is None:
|
||||
rv = self.dispatch_request()
|
||||
response = self.make_response(rv)
|
||||
response = self.process_response(response)
|
||||
try:
|
||||
rv = self.preprocess_request()
|
||||
if rv is None:
|
||||
rv = self.dispatch_request()
|
||||
response = self.make_response(rv)
|
||||
response = self.process_response(response)
|
||||
except Exception, e:
|
||||
response = self.make_response(self.handle_exception(e))
|
||||
return response(environ, start_response)
|
||||
|
||||
def request_context(self, environ):
|
||||
|
|
|
|||
|
|
@ -645,6 +645,28 @@ class LoggingTestCase(unittest.TestCase):
|
|||
assert '1/0' in err
|
||||
assert 'ZeroDivisionError:' in err
|
||||
|
||||
def test_processor_exceptions(self):
|
||||
app = flask.Flask(__name__)
|
||||
@app.before_request
|
||||
def before_request():
|
||||
if trigger == 'before':
|
||||
1/0
|
||||
@app.after_request
|
||||
def after_request(response):
|
||||
if trigger == 'after':
|
||||
1/0
|
||||
return response
|
||||
@app.route('/')
|
||||
def index():
|
||||
return 'Foo'
|
||||
@app.errorhandler(500)
|
||||
def internal_server_error(e):
|
||||
return 'Hello Server Error', 500
|
||||
for trigger in 'before', 'after':
|
||||
rv = app.test_client().get('/')
|
||||
assert rv.status_code == 500
|
||||
assert rv.data == 'Hello Server Error'
|
||||
|
||||
|
||||
def suite():
|
||||
from minitwit_tests import MiniTwitTestCase
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue