gmile

gmile

Tracking down slow queries in Ecto

Sometimes, Ecto (actually, DBConnection) spills an error like this:

DBConnection.ConnectionError: ** (DBConnection.ConnectionError) connection not available and request was dropped from queue after 11963ms. This means requests are coming in and your connection pool cannot serve them fast enough. You can address this by:

  1. Ensuring your database is available and that you can connect to it
  2. Tracking down slow queries and making sure they are running fast enough
  3. Increasing the pool_size (although this increases resource consumption)

Item 2 in the list above suggests Tracking down slow queries. How do you locate the code that is sending a slow query to database, in production?

I’m curious how this can be done at scale because, for example, the codebase I am working on is vast, spanning over 1000 modules. There are tons of places in the code that may call database, and finding the right code is not that easy.

I recently noticed telemetry produced by Ecto includes stacktrace info, so maybe this could help tracing down code that produces slow queries. Has anyone tried that? If yes, how do you log/collect/store such stacktraces?

Most Liked

benwilson512

benwilson512

Author of Craft GraphQL APIs in Elixir with Absinthe
Repo.query!("select pg_sleep(5)", [], timeout: 1_000)

I’ve got this handy function for returning telemetry spans on a particular function:

def trace_ecto(fun) when is_function(fun, 0) do
    this_process = self()

    ref = make_ref()

    # here we're attaching a handler to the query event. When the query is performed in the same process as called this function
    # we want to basically "export" those values out to a list for investigation. Handlers are global though, so we need to
    # only `send` when we are in the current process.
    :telemetry.attach(
      "__help__",
      [:sensetra, :repo, :query],
      fn _, measurements, metadata, _config ->
        if self() == this_process do
          send(this_process, {ref, %{measurements: measurements, metadata: metadata}})
        end
      end,
      %{}
    )

    Repo.transaction(fun)

    :telemetry.detach("__help__")

    do_get_trace_messages(ref)
  end

  defp do_get_trace_messages(ref) do
    receive do
      {^ref, message} ->
        [message | do_get_trace_messages(ref)]
    after
      0 -> []
    end
  end

Basically you call trace_ecto(fn -> your_funciton_here() end) and it returns all of the ecto telemetry emitted by that function!

EDIT: Oh on second thought I really need to set it up to rescue or something to catch those timeouts as the actual return value. You still get them from the send though it just ends up in your mailbox and you have to flush() them out. Will post an updated version shortly.

davydog187

davydog187

You should consider integrating OpenTelemetry with OpenTelemetryEcto that will capture spans for your Ecto queries, and then ship them to a good observability tool like https://www.honeycomb.io/ or https://www.servicenow.com/products/observability.html

I wrote about this around a year ago and there’s another good post that goes into more practical detail

benwilson512

benwilson512

Author of Craft GraphQL APIs in Elixir with Absinthe

One of the more recent versions of Ecto added a stacktrace: true option that you can set on the repo. This provides a stacktrace for the query in the ecto telemetry handlers.

From there it’s mostly a matter of figuring out how you want to consume that information. The quick and dirty way is to just log any queries that took longer than a chosen threshold.

Where Next?

Popular in Questions Top

albydarned
Hello all! I am typing this post from my new MacBook Pro with the M1 chip. I’m loving it so far, and will probably use it as my daily dr...
New
skosch
To my knowledge, put_in, Map.update etc. all have the one limitation of not automatically creating intermediate keys when needed (for exa...
New
fireproofsocks
I’m working on defining a simple Ecto schema for a table (in PostGres), but I don’t see where I can define a column as NOT NULL. Conside...
New
tduccuong
Hi, is there any work on GUI with Elixir, that is similar to Electron/Javascript? My idea is to bundle Phoenix and BEAM into a single se...
New
ycv005
I have followed this StackOverflow post to install the specific version of Erlang. And When I am running mix ecto.setup then getting fol...
New
jaysoifer
Is there a way to rollback a specific migration and only that one (“skipping” all the other ones)? Would mix ecto.rollback -v 200809061...
New
beno
I will often find my self writing things similar to: case some_value do nil -> something() "" -> something() _ -> somethi...
New
alice
Hey, Just curious what are the main benefits of Elixir compared to Clojure? When is Elixir more useful than Clojure and vice versa? Th...
New
sergio_101
I am VERY much an elixir newbie. I have taken one elixir course and one phoenix course on Udemy. During that course, I saw the instructor...
New
jononomo
For some reason my phoenix channels are working for me in my local dev environment, but as soon as I deploy via Docker, I get a 403 error...
New

Other popular topics Top

aadeshere1
I have a another noob question about loop. Since elixir is immutable, while loop is not directly possible. total = 10 while total != 0 ...
New
gshaw
What is the idiomatic way of matching for not nil in Elixir? E.g., First way: defp halt_if_not_signed_in(conn, signed_in_account) when...
New
electic
Hi, I am new to Elixir. I am trying to use the DateTime component to insert a date into MySQL however the there seems to be no way to fo...
New
minhajuddin
I have seen a lot of code which picks the first element from a list using Enum.at(0) instead of List.first. Is there a reason why people ...
New
vrod
I am using the Starship cross-shell prompt – it seems pretty nice, but I get some errors: [WARN] - (starship::utils): Executing command ...
New
alice
Hey, Just curious what are the main benefits of Elixir compared to Clojure? When is Elixir more useful than Clojure and vice versa? Th...
New
grych
Hi folks, Few months ago I have announced the proof-of-concept of the library to manipulate the browsers DOM objects directly from Elixi...
639 52341 488
New
sergio_101
I am VERY much an elixir newbie. I have taken one elixir course and one phoenix course on Udemy. During that course, I saw the instructor...
New
dblack
I’ve got an issue with an app and I’ve no idea of how to troubleshoot it. I’m hoping someone here might have seen something similar. I p...
New
joaquinalcerro
Hi there, I am working with Ecto-Postgresql and I need to call all of the records from a specific table but the table has 40,000 records...
New

We're in Beta

About us Mission Statement