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!
1 Answer
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)
print ('end')
return 'success'
A request to this endpoint, results in the following summary in the termainl:
* 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. Seepstats.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.
cProfile
works well for it.cProfile
and visualize the result usingsnakeview
or somethin else.