How to profile flask endpoint?

Question

I would like to profile a flask apps endpoint to see where it is slowing down when executing the endpoints functions. I have tried using Pycharms built-in profiler but the output tells me that most time is spent in the wait function i.e waiting for user input. I have tried installing the flask-profiler but was not able to set it up due to a project structure different than the package was expecting. Any help is appreciated. Thank you!

Answer 1

Werkzeug has a built in application profiler based on cProfile.

With help from this gist I managed to set it up as follows:

from flask import Flask
from werkzeug.middleware.profiler import ProfilerMiddleware
from time import sleep

app = Flask(__name__)
app.wsgi_app = ProfilerMiddleware(app.wsgi_app)

@app.route('/')
def index():
    print ('begin')
    sleep(3) # simulate delay
    print ('end')
    return 'success'

A request to this endpoint, results in the following summary in the terminal:

 * Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)
begin
end
--------------------------------------------------------------------------------
PATH: '/'
         298 function calls in 2.992 seconds

   Ordered by: internal time, call count

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    2.969    2.969    2.969    2.969 {built-in method time.sleep}
        1    0.002    0.002    0.011    0.011 /usr/local/lib/python3.7/site-packages/flask/app.py:1955(finalize_request)
        1    0.002    0.002    0.008    0.008 /usr/local/lib/python3.7/site-packages/werkzeug/wrappers/base_response.py:173(__init__)
       35    0.002    0.000    0.002    0.000 {built-in method builtins.isinstance}
        4    0.001    0.000    0.001    0.000 /usr/local/lib/python3.7/site-packages/werkzeug/datastructures.py:910(_unicodify_header_value)
        2    0.001    0.000    0.003    0.002 /usr/local/lib/python3.7/site-packages/werkzeug/datastructures.py:1298(__setitem__)
        1    0.001    0.001    0.001    0.001 /usr/local/lib/python3.7/site-packages/werkzeug/datastructures.py:960(__getitem__)
        6    0.001    0.000    0.001    0.000 /usr/local/lib/python3.7/site-packages/werkzeug/_compat.py:210(to_unicode)
        2    0.000    0.000    0.002    0.001 /usr/local/lib/python3.7/site-packages/werkzeug/datastructures.py:1212(set)
        4    0.000    0.000    0.000    0.000 {method 'decode' of 'bytes' objects}
        1    0.000    0.000    0.002    0.002 /usr/local/lib/python3.7/site-packages/werkzeug/wrappers/base_response.py:341(set_data)
       10    0.000    0.000    0.001    0.000 /usr/local/lib/python3.7/site-packages/werkzeug/local.py:70(__getattr__)
        8    0.000    0.000    0.000    0.000 {method 'get' of 'dict' objects}
        1    0.000    0.000    0.008    0.008 /usr/local/lib/python3.7/site-packages/flask/app.py:2029(make_response)
        1    0.000    0.000    0.004    0.004 /usr/local/lib/python3.7/site-packages/werkzeug/routing.py:1551(bind_to_environ)
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python3.7/site-packages/werkzeug/_internal.py:67(_get_environ)
        1    0.000    0.000    0.001    0.001 /usr/local/lib/python3.7/site-packages/werkzeug/routing.py:1674(__init__)

[snipped for berevity]

You could limit the results down slightly by passing a restrictions argument:

restrictions (Iterable[Union[str, int, float]]) – A tuple of restrictions to filter stats by. See pstats.Stats.print_stats().

So, for example if you were interested in the python file living at /code/app.py specifically, you could instead define the profiler like:

app.wsgi_app = ProfilerMiddleware(app.wsgi_app, restrictions=('/code/app.py',))

Resulting in the output:

 * Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)
begin
end
--------------------------------------------------------------------------------
PATH: '/'
         300 function calls in 3.016 seconds

   Ordered by: internal time, call count
   List reduced from 131 to 2 due to restriction <'/code/app.py'>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    3.007    3.007 /code/app.py:12(index)
        1    0.000    0.000    2.002    2.002 /code/app.py:9(slower)


--------------------------------------------------------------------------------

With some tweaking this could prove useful to solve your issue.