Profile execution time on a route

Profile execution time on a route

By running laputa with the environment variable PROFILER_MIDDLEWARE=enable, every http request will write a .prof file on your filesystem (in the working directory used when launching laputa).

This .prof file can then be analyzed using a tool like Snakeviz

Example

In a terminal I run laputa with the profiler enabled:

$ PROFILER_MIDDLEWARE=enable toucan-ctl runserver
...
Running on http://0.0.0.0:5000/ (Press CTRL+C to quit)

In another terminal I run an http request:

$ curl http://localhost:5000
{"status":"OK","version":"v101.0.2"}

It should have generated a .prof file:

$ ls *.prof
GET.root.7ms.1653317223.prof

Let's analyze it with snakeviz. If you don't have snakeviz installed:

$ pip install snakeviz

Then (this will open a new tab in your web browser):

$ snakeviz GET.root.7ms.1653317223.prof

You should see something like this:

We can see that the route takes 6ms to execute, and that most of the time is spent in flask routing and in instance_settings retrieval. The actual code of the route, Status.get, is a small square hidden somewhere, and only takes 0.00143ms to run (it does nothing).