2018-01-16T20:22:10Z

The Flask Mega-Tutorial Part VII: Error Handling

This is the seventh installment of the Flask Mega-Tutorial series, in which I'm going to tell you how to do error handling in a Flask application.

For your reference, below is a list of the articles in this series.

Note 1: If you are looking for the legacy version of this tutorial, it's here.

Note 2: If you would like to support my work on this blog, or just don't have patience to wait for weekly articles, I am offering the complete version of this tutorial packaged as an ebook or a set of videos. For more information, visit courses.miguelgrinberg.com.

In this chapter I'm taking a break from coding new features into my microblog application, and instead will discuss a few strategies to deal with bugs, which invariably make an appearance in any software project. To help illustrate this topic, I intentionally let a bug slip in the code that I've added in Chapter 6. Before you continue reading, see if you can find it!

The GitHub links for this chapter are: Browse, Zip, Diff.

Error Handling in Flask

What happens when an error occurs in a Flask application? The best way to find out is to experience it first hand. Go ahead and start the application, and make sure you have at least two users registered. Log in as one of the users, open the profile page and click the "Edit" link. In the profile editor, try to change the username to the username of another user that is already registered, and boom! This is going to bring a scary looking "Internal Server Error" page:

Internal Server Error

If you look in the terminal session where the application is running, you will see a stack trace of the error. Stack traces are extremely useful in debugging errors, because they show the sequence of calls in that stack, all the way to the line that produced the error:

(venv) $ flask run
 * Serving Flask app "microblog"
 * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
[2017-09-14 22:40:02,027] ERROR in app: Exception on /edit_profile [POST]
Traceback (most recent call last):
  File "/home/miguel/microblog/venv/lib/python3.6/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
    context)
  File "/home/miguel/microblog/venv/lib/python3.6/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
    cursor.execute(statement, parameters)
sqlite3.IntegrityError: UNIQUE constraint failed: user.username

The stack trace indicates what is the bug. The application allows a user to change the username, and does not validate that the new username chosen does not collide with another user already in the system. The error comes from SQLAlchemy, which tries to write the new username to the database, but the database rejects it because the username column is defined with unique=True.

It is important to note that the error page that is presented to the user does not provide much information about the error, and that is good. I definitely do not want users to learn that the crash was caused by a database error, or what database I'm using, or what are some of the table and field names in my database. All that information should be kept internal.

There are a few things that are far from ideal. I have an error page that is very ugly and does not match the application layout. I also have important application stack traces being dumped on a terminal that I need to constantly watch to make sure I don't miss any errors. And of course I have a bug to fix. I'm going to address all these issues, but first, let's talk about Flask's debug mode.

Debug Mode

The way you saw that errors are handled above is great for a system that is running on a production server. If there is an error, the user gets a vague error page (though I'm going to make this error page nicer), and the important details of the error are in the server process output or in a log file.

But when you are developing your application, you can enable debug mode, a mode in which Flask outputs a really nice debugger directly on your browser. To activate debug mode, stop the application, and then set the following environment variable:

(venv) $ export FLASK_DEBUG=1

If you are on Microsoft Windows, remember to use set instead of export.

After you set FLASK_DEBUG, restart the server. The output on your terminal is going to be slightly different than what you are used to see:

(venv) microblog2 $ flask run
 * Serving Flask app "microblog"
 * Forcing debug mode on
 * Running on http://127.0.0.1:5000/ (Press CTRL+C to quit)
 * Restarting with stat
 * Debugger is active!
 * Debugger PIN: 177-562-960

Now make the application crash one more time to see the interactive debugger in your browser:

Flask Debugger

The debugger allows you expand each stack frame and see the corresponding source code. You can also open a Python prompt on any of the frames and execute any valid Python expressions, for example to check the values of variables.

It is extremely important that you never run a Flask application in debug mode on a production server. The debugger allows the user to remotely execute code in the server, so it can be an unexpected gift to a malicious user who wants to infiltrate your application or your server. As an additional security measure, the debugger running in the browser starts locked, and on first use will ask for a PIN number, which you can see in the output of the flask run command.

Since I am in the topic of debug mode, I should mention the second important feature that is enabled with debug mode, which is the reloader. This is a very useful development feature that automatically restarts the application when a source file is modified. If you run flask run while in debug mode, you can then work on your application and any time you save a file, the application will restart to pick up the new code.

Custom Error Pages

Flask provides a mechanism for an application to install its own error pages, so that your users don't have to see the plain and boring default ones. As an example, let's define custom error pages for the HTTP errors 404 and 500, the two most common ones. Defining pages for other errors works in the same way.

To declare a custom error handler, the @errorhandler decorator is used. I'm going to put my error handlers in a new app/errors.py module.

app/errors.py: Custom error handlers

from flask import render_template
from app import app, db

@app.errorhandler(404)
def not_found_error(error):
    return render_template('404.html'), 404

@app.errorhandler(500)
def internal_error(error):
    db.session.rollback()
    return render_template('500.html'), 500

The error functions work very similarly to view functions. For these two errors, I'm returning the contents of their respective templates. Note that both functions return a second value after the template, which is the error code number. For all the view functions that I created so far, I did not need to add a second return value because the default of 200 (the status code for a successful response) is what I wanted. In this case these are error pages, so I want the status code of the response to reflect that.

The error handler for the 500 errors could be invoked after a database error, which was actually the case with the username duplicate above. To make sure any failed database sessions do not interfere with any database accesses triggered by the template, I issue a session rollback. This resets the session to a clean state.

Here is the template for the 404 error:

app/templates/404.html: Not found error template

{% extends "base.html" %}

{% block content %}
    <h1>File Not Found</h1>
    <p><a href="{{ url_for('index') }}">Back</a></p>
{% endblock %}

And here is the one for the 500 error:

app/templates/500.html: Internal server error template

{% extends "base.html" %}

{% block content %}
    <h1>An unexpected error has occurred</h1>
    <p>The administrator has been notified. Sorry for the inconvenience!</p>
    <p><a href="{{ url_for('index') }}">Back</a></p>
{% endblock %}

Both templates inherit from the base.html template, so that the error page has the same look and feel as the normal pages of the application.

To get these error handlers registered with Flask, I need to import the new app/errors.py module after the application instance is created:

app/__init__.py: Import error handlers

# ...

from app import routes, models, errors

If you set FLASK_DEBUG=0 in your terminal session and then trigger the duplicate username bug one more time, you are going to see a slightly more friendly error page.

Custom 500 Error Page

Sending Errors by Email

The other problem with the default error handling provided by Flask is that there are no notifications, stack trace for errors are printed to the terminal, which means that the output of the server process needs to be monitored to discover errors. When you are running the application during development, this is perfectly fine, but once the application is deployed on a production server, nobody is going to be looking at the output, so a more robust solution needs to be put in place.

I think it is very important that I take a proactive approach regarding errors. If an error occurs on the production version of the application, I want to know right away. So my first solution is going to be to configure Flask to send me an email immediately after an error, with the stack trace of the error in the email body.

The first step is to add the email server details to the configuration file:

config.py: Email configuration

class Config(object):
    # ...
    MAIL_SERVER = os.environ.get('MAIL_SERVER')
    MAIL_PORT = int(os.environ.get('MAIL_PORT') or 25)
    MAIL_USE_TLS = os.environ.get('MAIL_USE_TLS') is not None
    MAIL_USERNAME = os.environ.get('MAIL_USERNAME')
    MAIL_PASSWORD = os.environ.get('MAIL_PASSWORD')
    ADMINS = ['your-email@example.com']

The configuration variables for email include the server and port, a boolean flag to enable encrypted connections, and optional username and password. The five configuration variables are sourced from their environment variable counterparts. If the email server is not set in the environment, then I will use that as a sign that emailing errors needs to be disabled. The email server port can also be given in an environment variable, but if not set, the standard port 25 is used. Email server credentials are by default not used, but can be provided if needed. The ADMINS configuration variable is a list of the email addresses that will receive error reports, so your own email address should be in that list.

Flask uses Python's logging package to write its logs, and this package already has the ability to send logs by email. All I need to do to get emails sent out on errors is to add a SMTPHandler instance to the Flask logger object, which is app.logger:

app/__init__.py: Log errors by email

import logging
from logging.handlers import SMTPHandler

# ...

if not app.debug:
    if app.config['MAIL_SERVER']:
        auth = None
        if app.config['MAIL_USERNAME'] or app.config['MAIL_PASSWORD']:
            auth = (app.config['MAIL_USERNAME'], app.config['MAIL_PASSWORD'])
        secure = None
        if app.config['MAIL_USE_TLS']:
            secure = ()
        mail_handler = SMTPHandler(
            mailhost=(app.config['MAIL_SERVER'], app.config['MAIL_PORT']),
            fromaddr='no-reply@' + app.config['MAIL_SERVER'],
            toaddrs=app.config['ADMINS'], subject='Microblog Failure',
            credentials=auth, secure=secure)
        mail_handler.setLevel(logging.ERROR)
        app.logger.addHandler(mail_handler)

As you can see, I'm only going to enable the email logger when the application is running without debug mode, which is indicated by app.debug being True, and also when the email server exists in the configuration.

Setting up the email logger is somewhat tedious due to having to handle optional security options that are present in many email servers. But in essence, the code above creates a SMTPHandler instance, sets its level so that it only reports errors and not warnings, informational or debugging messages, and finally attaches it to the app.logger object from Flask.

There are two approaches to test this feature. The easiest one is to use the SMTP debugging server from Python. This is a fake email server that accepts emails, but instead of sending them, it prints them to the console. To run this server, open a second terminal session and run the following command on it:

(venv) $ python -m smtpd -n -c DebuggingServer localhost:8025

Leave the debugging SMTP server running and go back to your first terminal and set export MAIL_SERVER=localhost and MAIL_PORT=8025 in the environment (use set instead of export if you are using Microsoft Windows). Make sure the FLASK_DEBUG variable is set to 0 or not set at all, since the application will not send emails in debug mode. Run the application and trigger the SQLAlchemy error one more time to see how the terminal session running the fake email server shows an email with the full stack trace of the error.

A second testing approach for this feature is to configure a real email server. Below is the configuration to use your Gmail account's email server:

export MAIL_SERVER=smtp.googlemail.com
export MAIL_PORT=587
export MAIL_USE_TLS=1
export MAIL_USERNAME=<your-gmail-username>
export MAIL_PASSWORD=<your-gmail-password>

If you are using Microsoft Windows, remember to use set instead of export in each of the statements above.

The security features in your Gmail account may prevent the application from sending emails through it unless you explicitly allow "less secure apps" access to your Gmail account. You can read about this here, and if you are concerned about the security of your account, you can create a secondary account that you configure just for testing emails, or you can enable less secure apps only temporarily to run this test and then revert back to the default.

Logging to a File

Receiving errors via email is nice, but sometimes this isn't enough. There are some failure conditions that do not end in a Python exception and are not a major problem, but they may still be interesting enough to save for debugging purposes. For this reason, I'm also going to maintain a log file for the application.

To enable a file based log another handler, this time of type RotatingFileHandler, needs to be attached to the application logger, in a similar way to the email handler.

app/__init__.py: Logging to a file

# ...
from logging.handlers import RotatingFileHandler
import os

# ...

if not app.debug:
    # ...

    if not os.path.exists('logs'):
        os.mkdir('logs')
    file_handler = RotatingFileHandler('logs/microblog.log', maxBytes=10240,
                                       backupCount=10)
    file_handler.setFormatter(logging.Formatter(
        '%(asctime)s %(levelname)s: %(message)s [in %(pathname)s:%(lineno)d]'))
    file_handler.setLevel(logging.INFO)
    app.logger.addHandler(file_handler)

    app.logger.setLevel(logging.INFO)
    app.logger.info('Microblog startup')

I'm writing the log file with name microblog.log in a logs directory, which I create if it doesn't already exist.

The RotatingFileHandler class is nice because it rotates the logs, ensuring that the log files do not grow too large when the application runs for a long time. In this case I'm limiting the size of the log file to 10KB, and I'm keeping the last ten log files as backup.

The logging.Formatter class provides custom formatting for the log messages. Since these messages are going to a file, I want them to have as much information as possible. So I'm using a format that includes the timestamp, the logging level, the message and the source file and line number from where the log entry originated.

To make the logging more useful, I'm also lowering the logging level to the INFO category, both in the application logger and the file logger handler. In case you are not familiar with the logging categories, they are DEBUG, INFO, WARNING, ERROR and CRITICAL in increasing order of severity.

As a first interesting use of the log file, the server writes a line to the logs each time it starts. When this application runs on a production server, these log entries will tell you when the server was restarted.

Fixing the Duplicate Username Bug

I have exploited the username duplication bug for too long. Now that I have showed you how to prepare the application to handle this type of errors, I can go ahead and fix it.

If you recall, the RegistrationForm already implements validation for usernames, but the requirements of the edit form are slightly different. During registration, I need to make sure the username entered in the form does not exist in the database. On the edit profile form I have to do the same check, but with one exception. If the user leaves the original username untouched, then the validation should allow it, since that username is already assigned to that user. Below you can see how I implemented the username validation for this form:

app/forms.py: Validate username in edit profile form.

class EditProfileForm(FlaskForm):
    username = StringField('Username', validators=[DataRequired()])
    about_me = TextAreaField('About me', validators=[Length(min=0, max=140)])
    submit = SubmitField('Submit')

    def __init__(self, original_username, *args, **kwargs):
        super(EditProfileForm, self).__init__(*args, **kwargs)
        self.original_username = original_username

    def validate_username(self, username):
        if username.data != self.original_username:
            user = User.query.filter_by(username=self.username.data).first()
            if user is not None:
                raise ValidationError('Please use a different username.')

The implementation is in a custom validation method, but there is an overloaded constructor that accepts the original username as an argument. This username is saved as an instance variable, and checked in the validate_username() method. If the username entered in the form is the same as the original username, then there is no reason to check the database for duplicates.

To use this new validation method, I need to add the original username argument in the view function, where the form object is created:

app/routes.py: Validate username in edit profile form.

@app.route('/edit_profile', methods=['GET', 'POST'])
@login_required
def edit_profile():
    form = EditProfileForm(current_user.username)
    # ...

Now the bug is fixed and duplicates in the edit profile form will be prevented in most cases. This is not a perfect solution, because it may not work when two or more processes are accessing the database at the same time. In that situation, a race condition could cause the validation to pass, but a moment later when the rename is attempted the database was already changed by another process and cannot rename the user. This is somewhat unlikely except for very busy applications that have a lot of server processes, so I'm not going to worry about it for now.

At this point you can try to reproduce the error one more time to see how the new form validation method prevents it.

160 comments

  • #151 Amar Nath Yogi said 2019-10-04T19:53:25Z

    While registering the Error 500 custom function, if we don't make a "db.session.rollback()" and simply return the render_template. For some reason the custom page is not attached in the response. And it returns the default 505 error page. But when I add "db.session.rollback()" then it work just fine. Can you explain why the function doesn't return the custom page without a rollback?

  • #152 Miguel Grinberg said 2019-10-04T22:19:23Z

    @Amar: this is explained in the article. If the error handler is invoked after a database error, then the database session is in a bad state and cannot be used. Because the template generated by the error handler might make database calls, you have to rollback the database session, so that it is operational again.

  • #153 HuserOz said 2019-10-06T09:57:32Z

    Hello Miguel, When i try to see the error log on the SMTP DebuggingServer, i get this error: OSError: [Errno 98] Address already in use I set the MAIL_SERVER to localhost and MAIL_PORT to 8025 and try to restart the DebuggingServer afterwards, but nothing changed. Thank you in advance for your help!

  • #154 Miguel Grinberg said 2019-10-07T21:58:07Z

    @HuserOz: you are already running some other application on port 8025. Maybe a previous instance of the same SMTP debugging server.

  • #155 Ryan Couper said 2019-11-20T02:43:02Z

    Hello, Thanks so much for creating this tutorial. I have benefited greatly from it. I have everything working up to and including utilising the debug smtp server that prints out the info on a separate command line. However when I attempt to use a real server's details I get an error. I have tried with smtp.gmail.com and smtp.office365.com, I have tried with and without MAIL_USERNAME and MAIL_PASSWORD environment variables set. I'm usually pretty good with following stack traces to the source of the bug but I'm struggling with this one. Here's the important bits: #... (this first part is as expected, DB violation error) File "c:\dev\vscworkspaces\pythonplay\microblog\venv\lib\site-packages\sqlalchemy\engine\default.py", line 581, in do_execute cursor.execute(statement, parameters) sqlite3.IntegrityError: UNIQUE constraint failed: user.username The above exception was the direct cause of the following exception: Traceback (most recent call last): File "c:\dev\vscworkspaces\pythonplay\microblog\venv\lib\site-packages\flask\app.py", line 2446, in wsgi_app response = self.full_dispatch_request() # … File "c:\dev\vscworkspaces\pythonplay\microblog\venv\lib\site-packages\sqlalchemy\engine\default.py", line 581, in do_execute cursor.execute(statement, parameters) sqlite3.IntegrityError: UNIQUE constraint failed: user.username The above exception was the direct cause of the following exception: Traceback (most recent call last): File "c:\dev\vscworkspaces\pythonplay\microblog\venv\lib\site-packages\flask\app.py", line 2446, in wsgi_app response = self.full_dispatch_request() # … [SQL: UPDATE user SET username=?, about_me=? WHERE user.id = ?] [parameters: ('jolly', 'This says something about Susan.\r\nI can add more to this.', 1)] (Background on this error at: http://sqlalche.me/e/gkpj) During handling of the above exception, another exception occurred: Traceback (most recent call last): File "C:\Users\Land Simulation\AppData\Local\Programs\Python\Python38-32\lib\logging\handlers.py", line 1008, in emit smtp = smtplib.SMTP(self.mailhost, port, timeout=self.timeout) # … File "C:\Users\Land Simulation\AppData\Local\Programs\Python\Python38-32\lib\socket.py", line 914, in getaddrinfo for res in _socket.getaddrinfo(host, port, family, type, proto, flags): socket.gaierror: [Errno 11001] getaddrinfo failed Call stack: File "C:\Users\Land Simulation\AppData\Local\Programs\Python\Python38-32\lib\threading.py", line 890, in _bootstrap self._bootstrap_inner() # … File "c:\dev\vscworkspaces\pythonplay\microblog\venv\lib\site-packages\flask\app.py", line 1890, in log_exception self.logger.error( Message: 'Exception on /edit_profile [POST]' Arguments: () I'm sure I'm making a silly mistake somewhere, but I cannot seem to find it. Do you have any suggestions?

  • #156 Miguel Grinberg said 2019-11-21T00:13:07Z

    @Ryan: the error that matters in your case is this: socket.gaierror: [Errno 11001] getaddrinfo failed This is typically a problem with the host and port combination, or any sort of filtering at your router or ISP that prevents a communication with the email server.

  • #157 Gabriel said 2019-11-27T08:32:54Z

    Hi Miguel! TOOO MUCH THANKS FOR YOUR TIME DOING THIS GREAT WORK!. Thanks. Im having this problem and I'm lost. flask run * Environment: production WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead. * Debug mode: off Traceback (most recent call last): File "d:\program files\python37\lib\runpy.py", line 193, in _run_module_as_main "__main__", mod_spec) File "d:\program files\python37\lib\runpy.py", line 85, in _run_code exec(code, run_globals) File "D:\Program Files\Python37\Scripts\flask.exe\__main__.py", line 9, in <module> File "d:\program files\python37\lib\site-packages\flask\cli.py", line 966, in main cli.main(prog_name="python -m flask" if as_module else None) File "d:\program files\python37\lib\site-packages\flask\cli.py", line 586, in main return super(FlaskGroup, self).main(*args, **kwargs) File "d:\program files\python37\lib\site-packages\click\core.py", line 717, in main rv = self.invoke(ctx) File "d:\program files\python37\lib\site-packages\click\core.py", line 1137, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) File "d:\program files\python37\lib\site-packages\click\core.py", line 956, in invoke return ctx.invoke(self.callback, **ctx.params) File "d:\program files\python37\lib\site-packages\click\core.py", line 555, in invoke return callback(*args, **kwargs) File "d:\program files\python37\lib\site-packages\click\decorators.py", line 64, in new_func return ctx.invoke(f, obj, *args, **kwargs) File "d:\program files\python37\lib\site-packages\click\core.py", line 555, in invoke return callback(*args, **kwargs) File "d:\program files\python37\lib\site-packages\flask\cli.py", line 848, in run_command app = DispatchingApp(info.load_app, use_eager_loading=eager_loading) File "d:\program files\python37\lib\site-packages\flask\cli.py", line 305, in __init__ self._load_unlocked() File "d:\program files\python37\lib\site-packages\flask\cli.py", line 330, in _load_unlocked self._app = rv = self.loader() File "d:\program files\python37\lib\site-packages\flask\cli.py", line 392, in load_app app = locate_app(self, import_name, None, raise_if_not_found=False) File "d:\program files\python37\lib\site-packages\flask\cli.py", line 240, in locate_app __import__(module_name) File "D:\apprural\app\__init__.py", line 24, in <module> if app.config['MAIL_SERVER']: KeyError: 'MAIL_SERVER'

  • #158 Miguel Grinberg said 2019-11-27T14:10:50Z

    @Gabriel: you need to add the environment variables that configure the email server. Review this article to learn about that.

  • #159 Akilan said 2020-01-20T10:09:27Z

    For the changes in "Fixing the Duplicate Username Bug", I receive below error [2020-01-20 15:37:37,023] ERROR in app: Exception on /edit_profile [POST] Traceback (most recent call last): File "c:\users\kmk6kor\venv\lib\site-packages\flask\app.py", line 2446, in wsgi_app response = self.full_dispatch_request() File "c:\users\kmk6kor\venv\lib\site-packages\flask\app.py", line 1952, in full_dispatch_request return self.finalize_request(rv) File "c:\users\kmk6kor\venv\lib\site-packages\flask\app.py", line 1967, in finalize_request response = self.make_response(rv) File "c:\users\kmk6kor\venv\lib\site-packages\flask\app.py", line 2097, in make_response "The view function did not return a valid response. The" TypeError: The view function did not return a valid response. The function either returned None or ended without a return statement. 127.0.0.1 - - [20/Jan/2020 15:37:37] "POST /edit_profile HTTP/1.1" 500 -

  • #160 Miguel Grinberg said 2020-01-20T11:08:00Z

    @Akilan: you have a view function that does not return anything. This is not allowed in Flask, all view functions must return a response.

Leave a Comment