How to Get Started with Logging in Flask

Logging is a crucial component in the software life cycle. It allows you to take a peek inside your application and understand what is happening, which helps you address the problems as they appear. Flask is one of the most popular web frameworks for Python and logging in Flask is based on the standard Python logging module. In this article, you will learn how to create a functional and effective logging system for your Flask application.

Prerequisites

Before proceeding with this article, ensure that you have a recent version of Python 3 installed on your machine. To best learn the concepts discussed here, you should also create a new Flask project so that you may try out all the code snippets and examples.

Create a new working directory and change into it with the command below:

mkdir flask-logging && cd flask-logging

Install the latest version of Flask with the following command.

pip install Flask

Getting started with logging in Flask

To get started, you need to create a new Flask application first. Go to the root directory of your project and create an app.py file.

code app.py

from flask import Flask

app = Flask(__name__)

@app.route("/")
def hello():
    return "Hello, World!"

@app.route("/info")
def info():
    return "Hello, World! (info)"

@app.route("/warning")
def warning():
    return "A warning message. (warning)"

In this example, a new instance of the Flask application (app) is created and three new routes are defined. When these routes are accessed, different functions will be invoked, and different strings will be returned.

Next, you can add logging calls to the info() and warning() functions so that when they are invoked, a message will be logged to the console.

. . .
@app.route("/info")
def info():
    app.logger.info("Hello, World!")
    return "Hello, World! (info)"


@app.route("/warning")
def warning():
    app.logger.warning("A warning message.")
    return "A warning message. (warning)"

The highlighted lines above show how to access the standard Python logging module via app.logger. In this example, the info() method logs Hello, World! at the INFO level, and the warning() method logs "A warning message" at the WARNING level. By default, both messages are logged to the console.

To test this logger, start the dev server using the following command:

flask run

 * Debug mode: off
WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on http://127.0.0.1:5000
Press CTRL+C to quit

Keep the Flask dev server running and open up a new terminal window. Run the following command to test the /warning route:

curl http://127.0.0.1:5000/warning

The following text should be returned:

A warning message. (warning)

And then, go back to the dev server window, and a log message should appear:

[2022-10-17 12:43:33,907] WARNING in app: A warning message.

As you can see, the output contains a lot more information than just the log message itself. The warning() method will automatically include the timestamp ([2022-09-24 17:18:06,304]), the log level (WARNING), and the program that logged this message (app).

However, if you visit the /info route, you will observe that the "Hello World!" message isn't logged as expected. That's because Flask ignores messages with log level lower than WARNING by default, but we'll show how you can customize this behavior shortly.

One more thing to note is that every time you make changes to your Flask application, such as adding more loggers or modifying related configurations, you need to stop the dev server (by pressing CTRL+C), and then restart it for the changes to take effect.

Understanding log levels

Log levels are used to indicate how urgent a log record is, and the logging module used under the hood by Flask offers six different log levels, each associated with an integer value: CRITICAL (50), ERROR (40), WARNING (30), INFO (20) and DEBUG (10). You can learn more about log levels and how they are typically used by reading this article.

Each of these log level has a corresponding method, which allows you to send log entry with that log level. For instance:

. . .
@app.route("/")
def hello():

    app.logger.debug("A debug message")
    app.logger.info("An info message")
    app.logger.warning("A warning message")
    app.logger.error("An error message")
    app.logger.critical("A critical message")

    return "Hello, World!"

However, when you run this code, only messages with log level higher than INFO will be logged. That is because you haven't configured this logger yet, which means Flask will use the default configurations leading to the dropping of the DEBUG and INFO messages.

Remember to restart the server before making a request to the / route:

curl http://127.0.0.1:5000/

[2022-07-18 11:47:39,589] WARNING in app: A warning message
[2022-07-18 11:47:39,590] ERROR in app: An error message
[2022-07-18 11:47:39,590] CRITICAL in app: A critical message

In the next section, we will discuss how to override the default Flask logging configurations so that you can customize its behavior according to your needs.

Configuring your logging system

Flask recommends that you use the logging.config.dictConfig() method to overwrite the default configurations. Here is an example:

from flask import Flask
from logging.config import dictConfig

dictConfig(
    {
        "version": 1,
        "formatters": {
            "default": {
                "format": "[%(asctime)s] %(levelname)s in %(module)s: %(message)s",
            }
        },
        "handlers": {
            "console": {
                "class": "logging.StreamHandler",
                "stream": "ext://sys.stdout",
                "formatter": "default",
            }
        },
        "root": {"level": "DEBUG", "handlers": ["console"]},
    }
)

app = Flask(__name__)

. . .

Let's take a closer look at this configuration. First of all, the version key represents the schema version and, at the time this article is written, the only valid option is 1. Having this key allows the schema format to evolve in the future while maintaining backward compatibility.

Next, the formatters key is where you specify formatting patterns for your log records. In this example, only a default formatter is defined. To define a format, you need to use LogRecord attributes, which always start with a % symbol.

For example, %(asctime)s indicates the timestamp in ASCII encoding, s indicates this attribute corresponds to a string. %(levelname)s is the log level, %(module)s is the name of the module that pushed the message, and finally, %(message)s is the message itself.

Inside the handlers key, you can create different handlers for your loggers. Handlers are used to push log records to various destinations. In this case, a console handler is defined, which uses the logging.StreamHandler library to push messages to the standard output. Also, notice that this handler is using the default formatter you just defined.

Finally, the root key is where you specify configurations for the root logger, which is the default logger unless otherwise specified. "level": "DEBUG" means this root logger will log any messages higher than or equal to DEBUG, and "handlers": ["console"] indicates this logger is using the console handler you just saw.

One last thing you should notice in this example is that the configurations are defined before the application (app) is initialized. It is recommended to configure logging behavior as soon as possible. If the app.logger is accessed before logging is configured, it will create a default handler instead, which could be in conflict with your configuration.

Formatting your log records

Let's take a closer look at how to format log records in Flask. In the previous section, we introduced some LogRecord attributes and discussed how you can use them to create custom log messages:

. . .

dictConfig(
    {
        "version": 1,
        "formatters": {
            "default": {
                "format": "[%(asctime)s] %(levelname)s | %(module)s >>> %(message)s",
            }
        },
        . . .
    }
)

. . .

@app.route("/")
def hello():
    app.logger.info("An info message")
    return "Hello, World!"

This configuration produces a log record that is formatted like this:

[2022-10-17 13:13:25,484] INFO | app >>> An info message

Some of the attributes support further customization. For example, you can customize how the timestamp is displayed by adding a datefmt key in the configurations:

. . .

dictConfig(
    {
        "version": 1,
        "formatters": {
            "default": {
                "format": "[%(asctime)s] %(levelname)s | %(module)s >>> %(message)s",
                "datefmt": "%B %d, %Y %H:%M:%S %Z",
            }
        },
        . . .
    }
)

. . .

This yields a timestamp in the following format:

[October 17, 2022 13:22:40 Eastern Daylight Time] INFO | app >>> An info message

You can read this article to learn more about customizing timestamps in Python. Besides %(asctime)s %(levelname)s , %(module)s, and %(message)s, there are several other LogRecord attributes available. You can find all of them in the linked documentation.

Logging to files

Logging to the console is great for development, but you will need a more persistent medium to store log records in production so that you may reference them in the future. A great way to start persisting your logs is to send them to local files on the server. Here's how to set it up:

. . .
dictConfig(
    {
        "version": 1,
        . . .
        "handlers": {
            "console": {
                "class": "logging.StreamHandler",
                "stream": "ext://sys.stdout",
                "formatter": "default",
            },
            "file": {
                "class": "logging.FileHandler",
                "filename": "flask.log",
                "formatter": "default",
            },
        },
        "root": {"level": "DEBUG", "handlers": ["console", "file"]},
    }
)
. . .
@app.route("/")
def hello():

    app.logger.debug("A debug message")

    return "Hello, World!"

A new file handler is added to the handlers object and it uses the logging.FileHandler class. It also defines a filename which specifies the path to the file where the logs are stored. In the root object, the file handler is also registered so that logs are sent to the console and the configured file.

Once you restart your server, make a request to the /hello and observe that a flask.log file is generated at the root directory of your project. You can view its contents the following command:

cat flask.log

. . .
[October 17, 2022 13:29:12 Eastern Daylight Time] DEBUG | app >>> A debug message

Rotating your log files

The FileHandler discussed above does not support log rotation so if you desire to rotate your log files, you can use either RotatingFileHandler or TimedRotatingFileHandler. They take the same parameters as FileHandler with some extra options.

For example, RotatingFileHandler takes two more parameters:

• maxBytes determines the maximum size of each log file. When the size limit is about to be exceeded, the file will be closed, and another file will be automatically created.
• backupCount specifies the number of files that will be retained on the disk, and the older files will be deleted. The retained files will be appended with a number extension .1, .2, and so on.

. . .

dictConfig(
    {
        "version": 1,
        . . .
        "handlers": {
            "size-rotate": {
                "class": "logging.handlers.RotatingFileHandler",
                "filename": "flask.log",
                "maxBytes": 1000000,
                "backupCount": 5,
                "formatter": "default",
            },
        },
        "root": {"level": "DEBUG", "handlers": ["size-rotate"]},
    }
)
. . .

Notice that we are using logging.handlers.RotatingFileHandler and not logging.RotatingFileHandler. In this example, this logging system will retain six files, from flask.log, flask.log.1 up to flask.log.5, and each one has a maximum size of 1MB.

On the other hand, TimedRotatingFileHandler splits the log files based on time. Here's how to use it:

. . .

dictConfig(
    {
        "version": 1,
        . . .
        "handlers": {
            "time-rotate": {
                "class": "logging.handlers.TimedRotatingFileHandler",
                "filename": "flask.log",
                "when": "D",
                "interval": 10,
                "backupCount": 5,
                "formatter": "default",
            },
        },
        "root": {
            "level": "DEBUG",
            "handlers": ["time-rotate"],
        },
    }
)
. . .

Theinterval specifies the time interval, and when specifies the unit, which could be any of the following:

• "S": seconds
• "M": minutes
• "H": hours
• "D": days
• "W0"-"W6": weekdays, "W0" indicates Sunday. You can also specify an atTime option, which determines at what time the rollover happens. The interval option is not used in this case.
• "midnight": creates a new file at midnight. You can also specify an atTime option, which determines at what time the rollover happens.

When we are using the TimedRotatingFileHandler, the old file will be appended a timestamp extension in the format %Y-%m-%d_%H-%M-%S (time-rotate.log.2022-07-19_13-02-13).

If you need more flexibility when it comes to log rotation, you're better off using a utility like logrotate instead as Python's file rotation handlers are not designed for heavy production workloads.

Logging HTTP requests

Since Flask is a web framework, your application will likely be handling many HTTP requests, and logging information about them will help you understand what is happening inside your application. To demonstrate relevant concepts, we'll setup a demo application where users can search for a location and get its current time, and then we will create a logging system for it (see the logging branch for the final implementation).

Start by cloning the repository to your machine using the following command:

git clone https://github.com/betterstack-community/flask-world-clock.git

Change into the project directory:

cd flask-world-clock

You can check the structure of this project using the tree command:

tree

flask-world-clock
├── LICENSE
├── README.md
├── app.py
├── requirements.txt
├── screenshot.png
├── templates
│   ├── fail.html
│   ├── home.html
│   ├── layout.html
│   └── success.html
└── worldClock.log

Install the required dependencies by running the command below:

pip install -r requirements.txt

Start the development server:

flask run

 * Debug mode: off
WARNING: This is a development server. Do not use it in a production deployment. Use a production WSGI server instead.
 * Running on http://127.0.0.1:5000
Press CTRL+C to quit

If you see this output, that means the world clock app is up and running. You can access it by visiting http://127.0.0.1:5000 in your browser. You should first land on the home page:

If you type in a query, and a location is successfully found. You should see the result page:

If a location is not found, then you should see the fail page:

This project also uses two API services, Nominatim which is a geolocation tool that returns a coordinate given a search query, and the Time API which gives you the current time based on coordinates. Please read the linked documentations if you don't know how to use them. This project will also use the requests module to make API requests, so make sure you have it installed.

from flask import Flask, request, render_template
import requests

app = Flask(__name__)


@app.route("/")
def home():

    return render_template("home.html")


@app.route("/search", methods=["POST"])
def search():

    # Get the search query
    query = request.form["q"]

    # Pass the search query to the Nominatim API to get a location
    location = requests.get(
        "https://nominatim.openstreetmap.org/search",
        {"q": query, "format": "json", "limit": "1"},
    ).json()

    # If a location is found, pass the coordinate to the Time API to get the current time
    if location:
        coordinate = [location[0]["lat"], location[0]["lon"]]

        time = requests.get(
            "https://timeapi.io/api/Time/current/coordinate",
            {"latitude": coordinate[0], "longitude": coordinate[1]},
        )

        return render_template("success.html", location=location[0], time=time.json())

    # If a location is NOT found, return the error page
    else:

        return render_template("fail.html")

Creating a logging system for your Flask project

Next, it is time for you to add logging to this application. The logging branch of the repository includes the complete setup.

You can start by setting up the configurations:

. . .
from logging.config import dictConfig


dictConfig(
    {
        "version": 1,
        "formatters": {
            "default": {
                "format": "[%(asctime)s] [%(levelname)s | %(module)s] %(message)s",
                "datefmt": "%B %d, %Y %H:%M:%S %Z",
            },
        },
        "handlers": {
            "console": {
                "class": "logging.StreamHandler",
                "formatter": "default",
            },
            "file": {
                "class": "logging.FileHandler",
                "filename": "worldClock.log",
                "formatter": "default",
            },
        },
        "root": {"level": "DEBUG", "handlers": ["console", "file"]},
    }
)

app = Flask(__name__)
. . .

Make sure you put the configurations before you declare the Flask application (app = Flask(__name__)). This configuration specifies a default formatter, which is tied to both console and file handler. And these handlers are then assigned to the root logger. The console handler will push the log records to the console, and the file handler will push the records to a file named worldClock.log.

Next, you can start creating logging calls for each route. For example, when users visit your application, they would first make a request to the home route. Therefore, you can assign that request a unique ID, and then you can log that ID like this:

from flask import session
import uuid

. . .

app = Flask(__name__)

app.secret_key = "<secret_key>"


@app.route("/")
def home():

    session["ctx"] = {"request_id": str(uuid.uuid4())}

    app.logger.info("A user visited the home page >>> %s", session["ctx"])

    return render_template("home.html")

This example uses sessions to store the request_id, and for the sessions to be secure, you need to create a secret key for your application.

Go ahead and do the same for the search route as well:

. . .
@app.route("/search", methods=["POST"])
def search():

    # Get the search query
    query = request.form["q"]
    app.logger.info(
        "A user performed a search. | query: %s >>> %s", query, session["ctx"]
    )

    # Pass the search query to the Nominatim API to get a location
    location = requests.get(
        "https://nominatim.openstreetmap.org/search",
        {"q": query, "format": "json", "limit": "1"},
    ).json()

    # If a location is found, pass the coordinate to the Time API to get the current time
    if location:

        app.logger.info(
            "A location is found. | location: %s >>> %s", location, session["ctx"]
        )

        coordinate = [location[0]["lat"], location[0]["lon"]]

        time = requests.get(
            "https://timeapi.io/api/Time/current/coordinate",
            {"latitude": coordinate[0], "longitude": coordinate[1]},
        )

        return render_template("success.html", location=location[0], time=time.json())

    # If a location is NOT found, return the error page
    else:

        app.logger.info("A location is NOT found. >>> %s", session["ctx"])

        return render_template("fail.html")

Besides logging information about the request, you can also log something about the response as well. To do that, create a function with the @app.after_request decorator.

. . .
@app.after_request
def logAfterRequest(response):

    app.logger.info(
        "path: %s | method: %s | status: %s | size: %s >>> %s",
        request.path,
        request.method,
        response.status,
        response.content_length,
        session["ctx"],
    )

    return response

Restart the dev server and go to http://127.0.0.1:5000, and you will see the following log entries being displayed.

[September 24, 2022 16:48:29 EDT] [INFO | app] A user visited the home page >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}
[September 24, 2022 16:48:29 EDT] [INFO | app] path: / | method: GET | status: 200 OK | size: 946 >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}

When a search action is successful:

[September 24, 2022 16:49:39 EDT] [INFO | app] A user performed a search. | query: new york >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}

If a location is found:

[September 24, 2022 16:49:40 EDT] [INFO | app] A location is found. | location: [{. . .}] >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}
[September 24, 2022 16:49:41 EDT] [INFO | app] path: /search | method: POST | status: 200 OK | size: 1176 >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}

If a location is not found:

[September 24, 2022 16:51:15 EDT] [INFO | app] A user performed a search. | query: idufvuiew >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}
[September 24, 2022 16:51:16 EDT] [INFO | app] A location is NOT found. >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}
[September 24, 2022 16:51:16 EDT] [INFO | app] path: /search | method: POST | status: 200 OK | size: 497 >>> {'request_id': 'd6b8c572-33b3-4510-b941-d177f49ca7de'}

Working with multiple loggers

In the previous examples, you are only using the root logger, but in fact, it is possible for you to create multiple loggers and configure them separately.

from flask import Flask
from logging.config import dictConfig
import logging

dictConfig(
    {
        "version": 1,
        "formatters": {
            . . .
        },
        "handlers": {
            . . .
        },
        "root": {"level": "DEBUG", "handlers": ["console"]},

        "loggers": {
            "extra": {
                "level": "INFO",
                "handlers": ["time-rotate"],
                "propagate": False,
            }
        },
    }
)

root = logging.getLogger("root")
extra = logging.getLogger("extra")

app = Flask(__name__)


@app.route("/")
def hello():

    root.debug("A debug message")
    root.info("An info message")
    root.warning("A warning message")
    root.error("An error message")
    root.critical("A critical message")

    extra.debug("A debug message")
    extra.info("An info message")
    extra.warning("A warning message")
    extra.error("An error message")
    extra.critical("A critical message")

    return "Hello, World!"

In the first highlighted section, an extra logger is defined. This logger has a minimum log level INFO, and it uses the handler time-rotate. However, notice that it has an extra option called propagate. It determines whether or not this logger should propagate to its parent, which is the root logger. The default value is True, which means messages logged to the extra logger will also be logged by the root logger, unless we set its value to False.

If you execute the above code, you will get the following output in the console:

[July 25, 2022 16:24:47 Eastern Daylight Time] [DEBUG | app] A debug message
[July 25, 2022 16:24:47 Eastern Daylight Time] [INFO | app] An info message
[July 25, 2022 16:24:47 Eastern Daylight Time] [WARNING | app] A warning message
[July 25, 2022 16:24:47 Eastern Daylight Time] [ERROR | app] An error message
[July 25, 2022 16:24:47 Eastern Daylight Time] [CRITICAL | app] A critical message

And the following logs in the flask.log file:

cat flask.log

[July 25, 2022 16:25:32 Eastern Daylight Time] [INFO | app] An info message
[July 25, 2022 16:25:32 Eastern Daylight Time] [WARNING | app] A warning message
[July 25, 2022 16:25:32 Eastern Daylight Time] [ERROR | app] An error message
[July 25, 2022 16:25:32 Eastern Daylight Time] [CRITICAL | app] A critical message

Notice that the DEBUG message is ignored here. By creating multiple loggers for your application, you can create a more complex logging system.

For example, previously, we mentioned that you can include contextual information in your log record like this:

app.logger.debug("A debug message: %s", "test message")

However, this method can be very inefficient since you'll have to micromanage each logging call, and sometimes the same information should be included in many different log records. To solve this problem, you can have the extra logger use a different formatter, which include custom information:

. . .
dictConfig(
    {
        "version": 1,
        "formatters": {
            "default": {
                "format": "[%(asctime)s] %(levelname)s | %(module)s >>> %(message)s",
                "datefmt": "%B %d, %Y %H:%M:%S %Z",
            },
            "extra": {
                "format": "[%(asctime)s] %(levelname)s | %(module)s >>> %(message)s >>> User: %(user)s",
                "datefmt": "%B %d, %Y %H:%M:%S %Z",
            },
        },
        "handlers": {
            "console1": {
                "class": "logging.StreamHandler",
                "stream": "ext://sys.stdout",
                "formatter": "default",
            },
            "console2": {
                "class": "logging.StreamHandler",
                "stream": "ext://sys.stdout",
                "formatter": "extra",
            },
        },
        "root": {"level": "DEBUG", "handlers": ["console1"]},
        "loggers": {
            "extra": {
                "level": "DEBUG",
                "handlers": ["console2"],
                "propagate": False,
            }
        },
    }
)
. . .

In this new configuration, the root logger uses the console1 handler, which applies the default formatter. The extra logger, on the other hand, uses the console2 handler, which applies the extra formatter. The extra formatter expects a custom field, %(user)s, and you can pass this user field using the extra parameter like this:

. . .
extra = logging.getLogger("extra")


@app.route("/")
def hello():
    extra.info("A user has visited the home page", extra={"user": "Jack"})
    return "Hello, World!"

Restart the Flask dev server, and visit the / route again. You should get the following log record:

[October 18, 2022 13:31:32 EDT] INFO | app >>> A user has visited the home page >>> User: Jack

One more thing to note is that the extra formatter always expects a user field, so if you have a log record without a user field, you should not use the extra formatter. This is also why you can not use the root logger with the extra formatter, because the root logger is also used by Flask to record internal logs, and they don't have a user field.

Centralizing your logs in the cloud

After your application has been deployed to production, it will start to generate logs which may be stored in various servers. It is very inconvenient having to log into each server just to check some log records. In such cases, it is probably better to use a cloud-based log management system such as Logtail, so that you can manage, monitor and analyze all your log records together.

To use Logtail in your Flask application, first make sure you have registered an account, and then go to the Sources page, click the Connect source button.

Next, give your source a name, and remember to choose Python as your platform.

After you've successfully created a new source, scroll down to the Installation instructions section. You can follow the instructions to install the necessary packages and connect your existing loggers to Logtail. However, if you prefer the standard Flask way, things are a little different.

Install the logtail-python package:

pip install logtail-python

Collecting logtail-python
 Downloading logtail_python-0.1.3-py2.py3-none-any.whl (8.0 kB)
. . .
Installing collected packages: msgpack, urllib3, idna, charset-normalizer, certifi, requests, logtail-python
Successfully installed certifi-2022.6.15 charset-normalizer-2.1.0 idna-3.3 logtail-python-0.1.3 msgpack-1.0.4 requests-2.28.1 urllib3-1.26.11

Setup the LogtailHandler like this:

. . .
dictConfig(
    {
        "version": 1,
        "formatters": {
            . . .
        },
        "handlers": {
            . . .
            "logtail": {
                "class": "logtail.LogtailHandler",
                "source_token": "qU73jvQjZrNFHimZo4miLdxF",
                "formatter": "default",
            },
        },
        "root": {"level": "DEBUG", "handlers": ["console", "file", "logtail"]},
    }
)

. . .

app.logger.debug("A debug message")

This time when you run the above code, your log messages will be sent to Logtail. Go to the Live tail page.

Conclusion

In this article, we briefly discussed how to start logging in Flask. Logging in Flask is based on Python's logging module, and in this tutorial, you learned how to create a logging system using its handlers, log levels, and formatters. However, we merely scratched the surface of the logging module, and it offers us lots of other functionalities such as the Filter object, the LoggerAdapter object and so on. You can read more about logging in Python in this article.

Thanks for reading, and happy logging!

Article by

Eric Hu

Eric is a technical writer with a passion for writing and coding, mainly in Python and PHP. He loves transforming complex technical concepts into accessible content, solidifying understanding while sharing his own perspective. He wishes his content can be of assistance to as many people as possible.

Got an article suggestion? Let us know

Next article

10 Best Practices for Logging in Python

This article describes 10 best practices to follow when logging in Python applications to produce high quality logs that will help you keep your application running smoothly

→

This work is licensed under a Creative Commons Attribution-NonCommercial-ShareAlike 4.0 International License.