How do Ecto telemetry events work?

Questions / Help
1

Hi Family how are you?

I have been reading about Ecto telemetry events, but I am not sure about how these telemetry events work.

for example the documentation says:

defmodule MyApp.Telemetry do
  def handle_event([:my_app, :repo, :query], measurements, metadata, config) do
    IO.inspect binding()
  end
end

This event is thrown when a query is performed. but I am not sure if this event is thrown automatically or really I need to write the execute command:

as is shown in the following code:

:telemetry.execute(
      [:credit_card_information, :repo, :query],
      %{query: 1},
      %{table: "customer"}
    )

For example, if I want to know how much time a query spent, how can I measure that?

  • :query_time - the time spent executing the query.

url documentation Ecto.Repo — Ecto v3.10.1

1 Like
2

It is thrown automatically. When in doubt, test it!

In your handle_event function the measurements argument will have the various measurements outlined in docs you linked to. Just remember to use System.convert_time_unit to make sure you get the result units you want.

3 Likes
3

Hi, @benwilson512 thank you very much for your help,
I tried to catch the Ecto event, but I have not succeeded.

Only I have been able to catch the Sale Telemety:20 but this is thrown using the sentence: telemetry.execute, as you can see in the following logs:

iex(1)> [info] [2023-05-01] [19:02:23.036] POST /v1/operations/customer/credit-cards
iex(1)> [info] [2023-05-01] [19:02:23.126] [Sale telemetry: 20] total for product
iex(1)> [info] [2023-05-01] [19:02:23.340] Sent 404 in 303ms

I caught it in event_handler methods as is shown:

defmodule Metrics.Instrumenter do
  require Logger

  def setup do
    events = [
      [:grocery, :store, :sale],
      [:credit_card_information, :repo, :query]
    ]

    :telemetry.attach_many(
      "telemetry-intro-instrumenter",
      events,
      &__MODULE__.handle_event/4,
      nil
    )
  end

  def handle_event([:grocery, :store, :sale], measurements, metadata, _config) do
    Logger.info("[Sale telemetry: #{measurements.total}] total for #{metadata.product}")
  end

  def handle_event([:credit_card_information, :repo, :query], measurements, metadata, _config) do
    Logger.info("[ROCHA DATA_BASE: #{inspect(measurements)}] DATABASE TEST #{inspect(metadata)}")
  end
end

My Ecto configuration is according Instrumenting Ecto queries | AppSignal documentation
My otp_app is the name of my application:

use Ecto.Repo,
    otp_app: :credit_card_information,
    adapter: Ecto.Adapters.Postgres

however, the event is not caught. And I do not know why :frowning:

4

Hey @rocha7778 do you call Metrics.Instrumenter.setup anywhere?

5

Yes in the start application:

defmodule CreditCardInformation.Application do
  use Application
  require Logger
  alias Metrics.Instrumenter

  @doc """
  Start the supervisor with a Postgres Database and a HTTP server
  """
  @impl true
  def start(_type, _args) do
    Logger.add_backend(TrxLoggerBackend)
    Instrumenter.setup()# < --- called here
    opts = [strategy: :one_for_one, name: __MODULE__]
    children = CowboyUtils.build_child_spec(CreditCardController)
    Supervisor.start_link(children, opts)
  end
end