Flask decorator to measure time taken for a request

Flask decorator to measure time taken for a request

In the previous articles on the Python decorator series, we have learnt decorators, how they work and to implement a simple function based decorator and a class based decorator and decorator that supports parameters. In this article, we will use flask's before_request and after_request decorator to measure time taken for a request to complete.


import time
from flask import Flask, request, jsonify, current_app, g as app_ctx

app = Flask(__name__)


@app.before_request
def logging_before():
    # Store the start time for the request
    app_ctx.start_time = time.perf_counter()


@app.after_request
def logging_after(response):
    # Get total time in milliseconds
    total_time = time.perf_counter() - app_ctx.start_time
    time_in_ms = int(total_time * 1000)
    # Log the time taken for the endpoint 
    current_app.logger.info('%s ms %s %s %s', time_in_ms, request.method, request.path, dict(request.args))
    return response


@app.get('/')
def home():
    # artificial delay
    time.sleep(1.3)
    return jsonify({'Hello': 'World!!'})


@app.get('/slow-request')
def slow_request():
    # artificial delay
    time.sleep(5)
    return jsonify({'msg': 'slow request'})


if __name__ == '__main__':
    app.run(debug=True)

Logs from console

[2021-05-16 11:43:32,177] INFO : 1304 ms GET / {}
[2021-05-16 11:43:41,822] INFO : 5003 ms GET /slow-request {}

How this works

  • On Flask application startup, typically when you run python app.py, Flask registers the functions logging_before and logging_after to the flask's hooks registry
  • From then, On receiving a web request flask executes the logging_before function and executes the actual code inside the api code and then logging_after gets executed finally.
  • All of these methods can have a shared local state variables in specific to these web request using from flask g as app_ctx
  • logging_before saves current time using time.perf_counter() as start_time
  • logging_after finds the difference from start_time and logs the message

If you find this article helpful, please do like and comment on this article. If you have any suggestions or feedbacks, feel free to comment.

In the next article, we will implement various kinds decorator recipes. Stay tuned for upcoming articles. Subscribe to the newsletter and Connect with me on twitter to get my future articles.

Did you find this article valuable?

Support sureshdsk.dev by becoming a sponsor. Any amount is appreciated!