Optimizing Phoenix endpoints using flamegraphs

Posted by Luc Tielen on 21-4-2021

In today’s post, I will show how we achieved a 5x performance improvement for one of our Elixir/Phoenix projects most used endpoints, without using any form of caching.

Some background

Before we dive into the actual performance optimization, let me take a moment to explain the original situation.

The project in question has a Javascript SPA frontend, backed by an Elixir application that uses Phoenix for serving JSON-API requests. Lately, we had been seeing slowdowns on one of our endpoints that returns a dynamic (non-cacheable) JSON response. In some cases the response time could even go up to 2 seconds, yikes!

Like these things often go, initially there was no performance problem on this particular endpoint. However, over time, the JSON data that got served became much bigger (sometimes even larger than 1MB). A second iteration of the code was needed to deal with this issue!

Finding the bottleneck

Like with all performance issues, we first need to get a good idea of where the actual problem is located. Just guessing and trying out some changes doesn’t work and is a guaranteed waste of time. Luckily, there exist tools for finding performance bottlenecks.

One such tool for analyzing performance is a “flamegraph”. An example of this is shown in the figure below. A flamegraph gives clear insight in where the application spends most of it time. The horizontal width of a “bar” indicates the percentage of time spent in a specific function (the full width of the graph being 100% of the time). Functions that are called from within another function, are stacked one layer above the current one, further dividing where time is spent (in that specific function).

Tooling for generating flamegraphs exist for many languages, including the BEAM ecosystem! I used the eflame library for generating the graph. You can install it using mix by adding it to your mix.exs file:

1
2
3
def deps do
  [{:eflame, "~> 1.0", only: :dev}]
end

After it is installed, it is straightforward to profile a Phoenix endpoint by wrapping the existing code with :eflame.apply/2:

1
2
3
4
5
6
7
8
9
def index(conn, params) do
  # Be sure to remove this once you are done profiling since it will slow down
  # your application!
  :eflame.apply(fn ->
    # ... some code here
    data = ...
    render(conn, "index.json", data: data)
  end, [])
end

Once you start your server and trigger the endpoint you want to profile, it will write a stacks.out to the directory you are in. This file can then be transformed into an interactive SVG using one of the scripts from the eflame repository:

1
$ stack_to_flame.sh < stacks.out > flame.svg

(Tip: Make a folder where you save all your *.out files, so you can compare the performance of various changes later).

For our application, this resulted in the following graph:

A quick look at the flamegraph reveals that the application is spending a lot of time in the following two areas:

1. JSON decoding the content stored in the database.
2. JSON encoding the data before sending it back to the frontend.

This is a consequence of the field being stored as jsonb in the DB / using field(:content, :map) in the schema. Ecto will automatically do conversions for these database columns between JSON and a native Elixir data type.

On a side note, this is completely different to what we initially expected. We were thinking/guessing that it was the database query that was slow, not the actual JSON decoding/encoding. This shows the importance of measuring!

Optimizing the code

After looking around in the code for some time, I determined that the backend never used any data inside the JSON column, and only stored it in the database. This was a great discovery! If we don’t process any of the data, we can leave the JSON-encoded content as-is, and store it directly in the database. When a user requests the content, we can read out the JSON string from the database and send it directly back to the user. This avoids many unneeded conversions between JSON and Elixir data.

I did some googling around and found this post on the Elixir forum of somebody who wanted to do something very similar, but the thread ended up dying before a solution was presented (which is also the reason for this blogpost 😉). I decided to try this out for myself and came up with the following solution:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
# VerbatimJSON is a struct that contains a JSON-encoded string.
defmodule VerbatimJSON do
  use Ecto.Type

  @type t :: %__MODULE__{ value: String.t() }

  defstruct [:value]

  def new(json) when is_binary(json) do
    %__MODULE__{value: json}
  end

  def new(json) when is_map(json) do
    new(Jason.encode!(json))
  end

  # The functions below from Ecto.Type allow Ecto to convert the
  # text in the database to be converted into this struct and vice-versa.
  # For more information, see: https://hexdocs.pm/ecto/Ecto.Type.html

  @impl Ecto.Type
  def type, do: :string

  @impl Ecto.Type
  def cast(json) when is_binary(json) do
    {:ok, new(json)}
  end

  def cast(_), do: :error

  @impl Ecto.Type
  def dump(json) do
    {:ok, json.value}
  end

  @impl Ecto.Type
  def load(json) when is_binary(json) do
    {:ok, new(json)}
  end

  def load(_), do: :error
end

# This is where the performance optimization happens, we don't need to
# JSON-encode the string, since this has already been done!
defimpl Jason.Encoder, for: VerbatimJSON do
  def encode(%VerbatimJSON{value: value}, _opts) when is_binary(value) do
    # Value is already encoded, we just return the underlying value!
    value
  end
end

Another thing we will need is a migration to turn the column into normal text:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
defmodule App.Repo.Migrations.ConvertContentToText do
  use Ecto.Migration

  def up do
    execute("""
    ALTER TABLE my_table
    ALTER COLUMN content
    TYPE text
    """)
  end

  def down do
    execute("""
    ALTER TABLE my_table
    ALTER COLUMN content
    TYPE jsonb
    USING content::jsonb
    """)
  end
end

And we need to update our model; converting the :map field to VerbatimJSON:

1
2
3
schema "my_table" do
  field(:content, VerbatimJSON)
end

That’s all that is needed for it to work. In the next part we will look into how it actually performs.

The results

The figure below shows what the (interactive) flamegraph looks like after performing the optimization:

As you can see, the graph has a very different shape now that all unneeded JSON conversions are skipped. The majority of the time is now spent executing the database query and also in rendering the final JSON result back to the client. What’s neat is that we can now even see the sleeps some of the processes are performing while waiting for result (for example from the database).

But in the end, all this is just relative data in percentages. What is the actual difference in performance you ask? After the optimization, requests now take around 400-500ms on average. This is much faster than the initial 2 seconds and is good enough for now. (Though we might revisit this later and optimize that query some more! 😁)

Wrapping up

In this post, I showed a way to improve Phoenix endpoints that deal with large JSON datastructures by making clever use of Ecto.Type. We achieved a performance increase of around 5x. Flamegraphs proved to be a valuable asset for us, giving a clear visual indication where the bottleneck was located.

The VerbatimJSON struct right now is a rather standalone thing and could be turned into a Hex package fairly easily. If you think you could make use of this, let us know in the comments section below 👇 and we will create a hex package for it!