# Telemetry
ExGram emits [`:telemetry`](https://hexdocs.pm/telemetry) events at key points
in its lifecycle, letting you integrate with any observability tool that speaks
the `:telemetry` protocol - including Prometheus (via
[`TelemetryMetrics`](https://hexdocs.pm/telemetry_metrics)),
[`OpenTelemetry`](https://opentelemetry.io/), or simple structured logging.
> ### OpenTelemetry {: .tip}
>
> To have OpenTelemetry traces and spans in your bots, use the [`OpentelemetryExGram`](https://hex.pm/packages/opentelemetry_ex_gram) library.
> It attaches to the events below and creates OTel spans automatically, with full
> context propagation across GenServer and spawn boundaries.
>
> See the [OpenTelemetry guide](opentelemetry.md) for setup instructions and
> available spans.
## Events overview
| Event | Description |
|---|---|
| `[:ex_gram, :bot, :init, :start\|:stop]` | Bot dispatcher initialization span |
| `[:ex_gram, :bot, :shutdown]` | Bot dispatcher shutting down |
| `[:ex_gram, :updates, :init, :start\|:stop]` | Updates worker initialization span (polling, webhook, noup, test) |
| `[:ex_gram, :updates, :shutdown]` | Updates worker shutting down |
| `[:ex_gram, :request, :start\|:stop\|:exception]` | Outbound Telegram API call |
| `[:ex_gram, :update, :start\|:stop\|:exception]` | Incoming update dispatched to the bot |
| `[:ex_gram, :handler, :start\|:stop\|:exception]` | Your `handle/2` callback invocation |
| `[:ex_gram, :middleware, :start\|:stop\|:exception]` | Each middleware in the pipeline |
| `[:ex_gram, :polling, :start\|:stop\|:exception]` | One polling cycle (fetch + dispatch) |
All events are spans and carry `duration` in `:native` time units on the `:stop` event.
The `:shutdown` events are point-in-time and carry `system_time`. Convert to milliseconds with:
```elixir
System.convert_time_unit(duration, :native, :millisecond)
```
See `ExGram.Telemetry` for the full metadata reference for each event.
## Attaching handlers
Use `:telemetry.attach/4` (one event) or `:telemetry.attach_many/4` (multiple
events) to subscribe. A handler is a 4-arity function:
`(event_name, measurements, metadata, config) -> any`.
```elixir
defmodule MyApp.Telemetry do
require Logger
def setup do
:telemetry.attach_many(
"my-app-ex-gram",
[
[:ex_gram, :bot, :init, :start],
[:ex_gram, :bot, :init, :stop],
[:ex_gram, :bot, :shutdown],
[:ex_gram, :updates, :init, :start],
[:ex_gram, :updates, :init, :stop],
[:ex_gram, :updates, :shutdown],
[:ex_gram, :request, :start],
[:ex_gram, :request, :stop],
[:ex_gram, :request, :exception],
[:ex_gram, :update, :start],
[:ex_gram, :update, :stop],
[:ex_gram, :handler, :start],
[:ex_gram, :handler, :stop],
[:ex_gram, :handler, :exception],
[:ex_gram, :middleware, :start],
[:ex_gram, :middleware, :stop],
[:ex_gram, :polling, :start],
[:ex_gram, :polling, :stop],
],
&__MODULE__.handle_event/4,
nil
)
end
def handle_event(event, measurements, metadata, _config) do
Logger.debug("Telemetry: #{inspect(event)} #{inspect(measurements)} #{inspect(metadata)}")
end
end
```
Call `MyApp.Telemetry.setup/0` in your `Application.start/2` before starting
your supervision tree.
## Tracking bot and updates lifecycle
The `:init` span and `:shutdown` events let you log when bots and their updates
workers come up or go down - useful for auditing restarts in production. The `:stop`
event carries a `duration` measurement so you can alert on slow startups:
```elixir
def handle_event([:ex_gram, :bot, :init, :start], _measurements, metadata, _) do
Logger.info("[ExGram] bot initializing bot=#{metadata.bot}")
end
def handle_event([:ex_gram, :bot, :init, :stop], measurements, metadata, _) do
duration_ms = System.convert_time_unit(measurements.duration, :native, :millisecond)
Logger.info("[ExGram] bot ready bot=#{metadata.bot} init_ms=#{duration_ms}")
end
def handle_event([:ex_gram, :bot, :shutdown], _measurements, metadata, _) do
Logger.warning("[ExGram] bot stopping bot=#{metadata.bot}")
end
def handle_event([:ex_gram, :updates, :init, :start], _measurements, metadata, _) do
Logger.info("[ExGram] updates worker initializing bot=#{metadata.bot} method=#{metadata.method}")
end
def handle_event([:ex_gram, :updates, :init, :stop], measurements, metadata, _) do
duration_ms = System.convert_time_unit(measurements.duration, :native, :millisecond)
Logger.info("[ExGram] updates worker ready bot=#{metadata.bot} method=#{metadata.method} init_ms=#{duration_ms}")
end
def handle_event([:ex_gram, :updates, :shutdown], _measurements, metadata, _) do
Logger.warning("[ExGram] updates worker stopping bot=#{metadata.bot} method=#{metadata.method}")
end
```
## Logging API requests
Log every outbound Telegram API call with its duration and result:
```elixir
def handle_event([:ex_gram, :request, :stop], measurements, metadata, _) do
duration_ms = System.convert_time_unit(measurements.duration, :native, :millisecond)
case metadata.result do
{:ok, _} ->
Logger.info("[ExGram] #{metadata.method} OK in #{duration_ms}ms bot=#{metadata.bot}")
{:error, error} ->
Logger.warning(
"[ExGram] #{metadata.method} ERROR in #{duration_ms}ms " <>
"code=#{error.code} message=#{error.message} bot=#{metadata.bot}"
)
end
end
def handle_event([:ex_gram, :request, :exception], measurements, metadata, _) do
duration_ms = System.convert_time_unit(measurements.duration, :native, :millisecond)
Logger.error(
"[ExGram] #{metadata.method} EXCEPTION in #{duration_ms}ms " <>
"kind=#{metadata.kind} reason=#{inspect(metadata.reason)} bot=#{metadata.bot}"
)
end
```
## Tracking update processing latency
Measure the full pipeline (middleware + routing) for each update:
```elixir
def handle_event([:ex_gram, :update, :stop], measurements, metadata, _) do
duration_ms = System.convert_time_unit(measurements.duration, :native, :millisecond)
Logger.info(
"[ExGram] update processed in #{duration_ms}ms " <>
"bot=#{metadata.bot} halted=#{metadata.halted}"
)
end
```
## Alerting on handler exceptions
The `[:ex_gram, :handler, :exception]` event fires when your `handle/2`
callback raises. Use it to alert or capture errors:
```elixir
def handle_event([:ex_gram, :handler, :exception], _measurements, metadata, _) do
Logger.error(
"[ExGram] handler raised in bot=#{metadata.bot} " <>
"handler=#{metadata.handler} kind=#{metadata.kind} " <>
"reason=#{inspect(metadata.reason)}"
)
# Forward to your error tracker (e.g. Sentry, Honeybadger)
# Sentry.capture_exception(metadata.reason, stacktrace: metadata.stacktrace)
end
```
## Prometheus metrics with `telemetry_metrics`
Add `{:telemetry_metrics, "~> 1.0"}` and `{:telemetry_poller, "~> 1.0"}` to
your app's deps, then define metrics:
```elixir
defmodule MyApp.Telemetry do
import Telemetry.Metrics
def metrics do
[
# Count bot starts and stops
counter("ex_gram.bot.init.stop.count", tags: [:bot]),
counter("ex_gram.bot.shutdown.count", tags: [:bot]),
# Distribution of bot initialization duration
distribution("ex_gram.bot.init.stop.duration",
unit: {:native, :millisecond},
tags: [:bot]
),
# Count updates worker starts and stops
counter("ex_gram.updates.init.stop.count", tags: [:bot, :method]),
counter("ex_gram.updates.shutdown.count", tags: [:bot, :method]),
# Count every API call
counter("ex_gram.request.stop.count",
tags: [:method, :bot]
),
# Distribution of API call durations
distribution("ex_gram.request.stop.duration",
unit: {:native, :millisecond},
tags: [:method, :bot],
reporter_options: [buckets: [10, 50, 100, 500, 1000, 5000]]
),
# Count API errors
counter("ex_gram.request.stop.error_count",
keep: &match?({:error, _}, &1.result),
tags: [:method, :bot]
),
# Count incoming updates
counter("ex_gram.update.stop.count",
tags: [:bot]
),
# Distribution of update processing time
distribution("ex_gram.update.stop.duration",
unit: {:native, :millisecond},
tags: [:bot]
),
# Count handler exceptions
counter("ex_gram.handler.exception.count",
tags: [:bot, :handler]
),
# Distribution of polling cycle durations
distribution("ex_gram.polling.stop.duration",
unit: {:native, :millisecond},
tags: [:bot]
),
]
end
end
```
## Middleware timing
If your bot has multiple middlewares, you can measure each one individually:
```elixir
def handle_event([:ex_gram, :middleware, :stop], measurements, metadata, _) do
duration_ms = System.convert_time_unit(measurements.duration, :native, :millisecond)
Logger.debug(
"[ExGram] middleware #{inspect(metadata.middleware)} in #{duration_ms}ms " <>
"bot=#{metadata.bot} halted=#{metadata.halted}"
)
end
```
## Handler vs. update events
It is worth understanding the distinction between update and handler events:
- **`[:ex_gram, :update, ...]`** - spans middleware execution and update routing.
When using async dispatch (the default), the stop event fires after the handler
_process is spawned_, not after the handler finishes. The duration reflects
middleware + routing overhead only.
- **`[:ex_gram, :handler, ...]`** - spans the actual `handle/2` callback. This
event always fires in the process executing the handler (the spawned process
for async dispatch, or the GenServer process for sync dispatch).
For end-to-end latency tracking, subscribe to `[:ex_gram, :handler, :stop]`.
