I use the Flask web development framework, written in Python, as the tool of choice for writing web applications. Its simple, lightweight, easy and well documented. It makes writing web applications a breeze – freeing me to write the important stuff.
Flask integrates into the Python API wherever possible and takes care of most things for you. When something goes badly wrong in your code Flask catches exceptions and sends them through Python’s logging framework. This is very useful – in addition to telling the user, Flask can be configured to send logging to a file and to e-mail, so I get to hear about it even if a user doesn’t report a fault. This is where tools like Sentry also fit in – although I don’t use them.
The problem is that default logging, whilst dumping a full stack trace, does not add any Flask or web-specific details. The log format only contains the default log record attributes:
Message type: ERROR Location: /usr/lib/python2.6/site-packages/flask/app.py:1306 Module: app Function: log_exception Time: 2013-05-03 15:35:57,170 Logger Name: bargate Process ID: 1877 Message: Exception on /login [POST]
The worst part of the above is the lack of relevant information, but also the fact that because the exception is handled by several wapper functions, the ‘Location’ and ‘Function’ and ‘Module’ parts are all irrelevant because they refer to the function dealing with the exception rather than where it was generated from.
Either way, I wanted to extend the log format (the emails generated) when exceptions occur. A thread on the Flask mailing list led me toward messing with subclassing parts of Python’s logging classes (as indicated by other developers), but this led me astray. After extensive reading of ‘logging’ and thinking about the problem in detail, I realised this was nonsense – there was no way to inject additional custom attributes into exception logs like that.
The way to do it is to inject custom data into a log with the “extra=” kwargs flag when calling “logger.error”. The problem of course is that code you write within Flask doesn’t (generally) call logger.error at all – Flask does this for you within app.log_exception. The solution then is deliciously simple – and a recommended way of using Flask – subclass Flask itself.
Thus I subclassed Flask like so:
class BargateFlask(Flask):
def log_exception(self, exc_info):
"""Logs an exception. This is called by :meth:`handle_exception`
if debugging is disabled and right before the handler is called.
This implementation logs the exception as error on the
:attr:`logger` but sends extra information such as the remote IP
address, the username, etc.
.. versionadded:: 0.8
"""
if 'username' in session:
usr = session['username']
else:
usr = 'Not logged in'
self.logger.error("""Path: %s
HTTP Method: %s
Client IP Address: %s
User Agent: %s
User Platform: %s
User Browser: %s
User Browser Version: %s
Username: %s
""" % (
request.path,
request.method,
request.remote_addr,
request.user_agent.string,
request.user_agent.platform,
request.user_agent.browser,
request.user_agent.version,
usr,
), exc_info=exc_info)
In the above example I decided not to use the extra kwargs flag and modify the Formatter object when setting up e-mail alerts as that would mean every call to app.logger.error would require me to send the same extra= flags. Instead I added the information I wanted via the message parameter (which achieves the same end result). This way, error e-mails are much more useful:
A fatal error occured in Bargate. Message type: ERROR Location: /data/fwa/bargate/__init__.py:104 Module: __init__ Function: log_exception Time: 2013-05-05 09:43:59,942 Logger Name: bargate Process ID: 12141 Further Details: Path: / HTTP Method: POST Client IP Address: 152.78.130.147 User Agent: Wget/1.11.4 Red Hat modified User Platform: None User Browser: None User Browser Version: None Username: Not logged in
