Profiling Elixir with Perf
In this post we will show you how to profile your Elixir application with perf and visualise its stack trace with Flamegraphs. We’ll create a basic Phoenix web server with two endpoints which we will call in order to profile and analyse its performance.
Requirements:
A Linux machine that can run the perf command
TLDR:
- Create a
mix release
of your application - Run it in daemon mode with JPperf enabled
- Pass the application’s process id into
perf
and record some activity - Visualise the outputted data file with the Flamegraph scripts
Why use Perf?
You might ask: “why should we use the perf tool for profiling Elixir? The BEAM ecosystem has numerous built-in tools for profiling”. And you would be right. The issue with these tools is that they can significantly slow down the program they profile. This might be okay if you want to profile a specific small use case of your program, but in this guide we want to demonstrate a process that works with profiling a production level application.
1. Creating our web server
We’re going to use a Phoenix application as our example for profiling with perf. You can follow what we did step by step below or skip to the next section by simply cloning the server in its final form here.
First we want to initiate our no-thrills Phoenix server (get set up with Phoenix here).
mix phx.new slow_server --no-html --no-assets --no-ecto
Now we could stop here and profile this application, but that would be pretty boring. So instead we’re going to add two endpoints:
-
POST
/api/fib
→ calculates and returns the nth Fibonacci number. -
GET
/api/desc
→ Will make a HTTP request of its own and return a description of Elixir.
Firstly, in order to make our HTTP request we are going to use the Req HTTP client library. So add {:req, "~> 0.3.0"}
as a dependency in your mix.exs
file and mix deps.get
After that we want to edit our router.ex
file to include our new endpoints we are going to call:
defmodule SlowServerWeb.Router do
use SlowServerWeb, :router
pipeline :api do
plug :accepts, ["json"]
end
scope "/api", SlowServerWeb do
pipe_through :api
get "/desc", ApiController, :desc
post "/fib", ApiController, :fib
end
end
Then we want to create our api_controller.ex
file that will look something like this:
defmodule SlowServerWeb.ApiController do
use SlowServerWeb, :controller
def desc(conn, _params) do
desc = Req.get!("https://api.github.com/repos/elixir-lang/elixir").body["description"]
resp(conn, 200, desc)
end
def fib(conn, %{"n" => n}) do
fib = SlowServer.Fibonacci.fib(n)
resp(conn, 200, Integer.to_string(fib))
end
end
We will leave it up to you to implement the Fibonacci function! Try running the server and making requests to the two new endpoints we’ve just created.
2. Getting production ready with mix release
As stated already, our goal is to profile our application as similar to its production state as possible. This way we can hopefully identify any issues that happen in the real world. In order to do that we will be using mix release. This assembles all of our code and the runtime into a single unit.
Firstly we need to run our mix release command with the environment set to production:
MIX_ENV=prod mix release
You should see instructions on how to run the built release. You may need to set a secret key to be used by Phoenix which you can set as such export SECRET_KEY_BASE=1234
Run our application with a command similar to the one below:
_build/prod/rel/slow_server/bin/slow_server start
Now lets test it by calling our endpoints:
➜ ~ curl http://localhost:4000/api/desc
Elixir is a dynamic, functional language \
for building scalable and maintainable applications%
➜ ~ curl -X POST -H "Content-Type: application/json" -d '{"n": 6}' \
http://localhost:4000/api/fib
8
Great! Now let’s actually profile our application.
3. Finally profiling
In order to profile our application we need to pass in a specific flag which enables support for perf: +JPperf true
. We’re also going to run our release in daemon mode so that it runs in the background. In order to do this run the following:
ERL_FLAGS="+JPperf true" _build/prod/rel/slow_server/bin/slow_server daemon
Next we want to get the process id of our application to profile.
BEAM_PID=$(_build/prod/rel/slow_server/bin/slow_server pid)
Now we are going to do the actual profiling with perf! This will output a data file containing the stack traces of our running application once we exit.
perf record -F 10000 -g -a --pid $BEAM_PID
In another terminal call our endpoints with the above curls, then return to our running perf and exit with ctrl-c. You should see some output along the lines of the following and a perf.data
output in the folder the command ran in.
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.092 MB perf.data (964 samples) ]
4. Flamegraphs
Now we could stop here, we’ve officially profiled our application! But instead let’s visualise this to really see what’s going on. We’re going to clone the Flamegraph repo inside of the folder you’ve created your perf.data
and then run these some commands to generate the graph.
git clone https://github.com/brendangregg/FlameGraph
mv perf.data FlameGraph/perf.data
cd FlameGraph
perf script | ./stackcollapse-perf.pl | ./flamegraph.pl > flame.html
This will give use our lovely outputted Flamegraphs, which should look something like this.
Can you figure out what I set to n
to from this Fibonacci flame graph?