Settings View Source Telemetry

Absinthe 1.5 and up uses telemetry to instrument its activity.

Call :telemetry.attach/4 or :telemetry.attach_many/4 to attach your handler function to any of the following event names:

• [:absinthe, :execute, :operation, :start] when the operation starts
• [:absinthe, :execute, :operation, :stop] when the operation finishes
• [:absinthe, :subscription, :publish, :start] when a subscription starts
• [:absinthe, :subscription, :publish, :stop] when a subscription finishes
• [:absinthe, :resolve, :field, :start] when field resolution starts
• [:absinthe, :resolve, :field, :stop] when field resolution finishes
• [:absinthe, :middleware, :batch, :start] when the batch processing starts
• [:absinthe, :middleware, :batch, :stop] when the batch processing finishes

Telemetry handlers are called with measurements and metadata. For details on what is passed, checkout Absinthe.Phase.Telemetry, Absinthe.Middleware.Telemetry, and Absinthe.Middleware.Batch.

For async, batch, and dataloader fields, Absinthe sends the final event when it gets the results. That might be later than when the results are ready. If you need to know how long the underlying operation took, you'll need to hook telemetry up to that underlying operation. See, for example, the recommended telemetry events in the documentation for Ecto.Repo.

Interactive Telemetry

As an example, you could attach a handler in an iex -S mix shell. Paste in:

:telemetry.attach_many(
  :demo,
  [
    [:absinthe, :resolve, :field, :stop]
  ],
  fn event_name, measurements, metadata, _config ->
    %{
      event_name: event_name,
      measurements: measurements,
      metadata: metadata
    }
    |> IO.inspect()
  end,
  []
)

After a query is executed, you'll see something like:

%{
  event_name: [:absinthe, :resolve, :field, :stop],
  measurements: %{duration: 14000},
  metadata: %{
    id: -576460752303351647,
    middleware: [
      {{Absinthe.Resolution, :call}, &MyApp.Resolvers.resolve_field/3}
    ],
    resolution: :...,
    start_time: 1565830447035742000
  }
}

Opentelemetry

When using Opentelemetry, one usually wants to correlate spans that are created in spawned tasks with the main trace. For example, you might have a trace started in a Phoenix endpoint, and then have spans around database access.

One can correlate manually by attaching the OTel context the task function:

ctx = OpenTelemetry.Ctx.get_current()

Task.async(fn ->
  OpenTelemetry.Ctx.attach(ctx)

  # do stuff that might create spans
end)

When using the async and batch middleware, the tasks are spawned by Absinthe, so you can't attach the context manually.

Instead, you can add the :opentelemetry_process_propagator package to your dependencies, which has a Task.async/1 wrapper that will attach the context automatically. If the package is installed, the middleware will use it in place of the default Task.async/1.