Skip to main content

guides/telemetry.md

# Telemetry

`wallet_passes` instruments every significant operation — building Apple
`.pkpass` bundles, calling the Google Wallet REST API, sending APNs pushes,
and dispatching wallet-event callbacks — using the standard Erlang
[`:telemetry`](https://hexdocs.pm/telemetry/) library. This guide is the
complete event reference plus a short primer on attaching handlers.

## Overview

Events live under one of three prefixes — `[:wallet_passes, :apple, …]`,
`[:wallet_passes, :google, …]`, and `[:wallet_passes, :event_handler, …]` —
and follow the standard `:start | :stop | :exception` pattern. They're
emitted unconditionally; if no handler is attached they're no-ops.

`:telemetry` is a hard dependency (added in 0.5.0), so you don't need to
declare it separately. Typical use cases:

- **Metrics** — wire to PromEx, StatsD, Telemetry.Metrics, Datadog.
- **Structured logging** — trace a serial number through build → push →
  callback.
- **Tracing** — forward span events to OpenTelemetry.
- **Alerting** — page when `:apple, :push, :stop` `error_count` > 0.

## Concepts

Skip to the [event reference](#event-reference) if you've used
`:telemetry` before.

### The start / stop / exception pattern

`:telemetry` standardises a three-event pattern around any operation:

- `[…, :start]` — measurements `%{system_time: integer()}`.
- `[…, :stop]` — measurements `%{duration: native_time}`.
- `[…, :exception]` — measurements `%{duration: native_time}`. Metadata
  gains `:kind`, `:reason`, and `:stacktrace`.

Most operations in this library use `:telemetry.span/3`, which emits all
three automatically. A couple use manual `:telemetry.execute/3` and don't
emit `:exception` — those are flagged below.

`duration` is in native time units. Convert via
`System.convert_time_unit(duration, :native, :microsecond)`.

### Measurements vs metadata

**Measurements** are numeric (durations, counts, bytes) and feed histograms
and counters. **Metadata** is contextual labels (serial numbers, IDs,
status atoms) and feeds metric dimensions / tags. Avoid using
high-cardinality metadata like raw serial numbers as Prometheus tags.

### Attaching handlers

Handlers are functions called synchronously when an event fires. Attach
them once at boot (typically in your `Application.start/2`):

```elixir
:telemetry.attach_many(
  "wallet-passes-handler",
  [
    [:wallet_passes, :apple, :build_pass, :stop],
    [:wallet_passes, :google, :save_url, :stop],
  ],
  &MyApp.WalletTelemetry.handle_event/4,
  _config = nil
)
```

The handler signature is `fn event, measurements, metadata, config -> :ok end`.
Handlers run in the calling process — keep them fast and side-effect-free,
or hand off to a `Task`.

## Event reference

In every table below, the `:start` event measurements are always
`%{system_time: integer()}` and the `:stop`/`:exception` events always
include `duration` (native time units). Only additional measurements are
documented per event.

### `[:wallet_passes, :apple, :build_pass, :start | :stop | :exception]`

Emitted around `WalletPasses.Apple.Builder.build_pkpass/4` — the full
`.pkpass` build pipeline (pass.json assembly, asset collection, manifest
hashing, PKCS#7 signing, ZIP packaging).

| Field                  | Type      | Notes                                |
|------------------------|-----------|--------------------------------------|
| Measurements (`:stop`) | `duration` | Native time units                   |
| Metadata               | `serial_number` | The `PassData.serial_number`   |

Uses `:telemetry.span/3`, so `:exception` fires on raised errors with
`:kind`, `:reason`, and `:stacktrace` metadata.

### `[:wallet_passes, :apple, :push, :start | :stop]`

Emitted around `WalletPasses.Apple.Push.notify_devices/1` — sending silent
APNs background pushes to one or more device push tokens.

| Field                  | Keys                                          |
|------------------------|-----------------------------------------------|
| Measurements (`:stop`) | `duration`, `success_count`, `error_count`    |
| Metadata               | `token_count` (number of tokens dispatched)   |

Uses manual `:telemetry.execute/3`. **No `:exception` event** — internal
errors are reported via the `success_count` / `error_count` measurements,
not raised. An empty push-token list still emits both events with all
counts at zero.

### `[:wallet_passes, :google, :create_or_update_class | :create_object | :update_object, …]`

Three separate event families, all emitted via `:telemetry.span/3` with
the standard `:start | :stop | :exception` triple, all of which add
`status: :ok | :error` to the `:stop` metadata.

| Event family                            | Wraps                                                         | Identifier metadata |
|-----------------------------------------|---------------------------------------------------------------|---------------------|
| `…, :google, :create_or_update_class`   | `Google.Api.create_or_update_class/2` (PUT, fallback to POST) | `class_id` (full `<issuer_id>.<suffix>`) |
| `…, :google, :create_object`            | `Google.Api.create_object/3` (POST, fallback to PUT on 409)   | `serial_number`     |
| `…, :google, :update_object`            | `Google.Api.update_object/4` (full-object PATCH)              | `object_id`         |

The identifier appears in both `:start` and `:stop` metadata; `status` is
added only to `:stop`. `:create_or_update_class` is also invoked by
`ensure_class/2` on the first observation of a class within a VM lifetime.

### `[:wallet_passes, :google, :update_object_state, :start | :stop | :exception]`

Emitted around `WalletPasses.Google.Api.update_object_state/3` — the
lightweight state-only PATCH used by the pass lifecycle transition
functions (`void_pass/1`, `expire_pass/1`, `complete_pass/1`,
`reactivate_pass/1`). Added in 0.7.0.

| Field               | Keys                                                |
|---------------------|-----------------------------------------------------|
| Metadata (`:start`) | `object_id`, `pass_type`, `state`                   |
| Metadata (`:stop`)  | `object_id`, `pass_type`, `state`, `status`         |

`state` is one of `"ACTIVE" | "INACTIVE" | "EXPIRED" | "COMPLETED"`.
`pass_type` is the atom (e.g., `:event_ticket`). `status` is `:ok` when the
HTTP response is 2xx, `:error` otherwise.

### `[:wallet_passes, :google, :token_exchange, :start | :stop | :exception]`

Emitted around `WalletPasses.Google.Api.get_access_token/0`. Fires for
every call, including cache hits.

| Field                  | Keys                                  |
|------------------------|---------------------------------------|
| Measurements (`:stop`) | `duration` (zero on cache hit)        |
| Metadata               | `cached` (`true` on ETS hit, `false` on miss) |

Cache hits emit start and stop synchronously with `duration: 0`. Cache
misses use `:telemetry.span/3` around the OAuth2 token exchange call and
emit `:exception` on raised errors.

### `[:wallet_passes, :google, :save_url, :start | :stop | :exception]`

Emitted around `WalletPasses.Google.SaveUrl.url/2` — building the JWT and
the `https://pay.google.com/gp/v/save/…` URL.

| Field    | Keys                                                                |
|----------|---------------------------------------------------------------------|
| Metadata | `serial_number` (extracted from `pass_object["id"]` after the dot)  |

If `pass_object["id"]` doesn't match the `<issuer>.<serial>` shape, the
metadata field contains the raw id; if the input isn't a map at all,
it's `nil`.

### `[:wallet_passes, :event_handler, :dispatch, :start | :stop]`

Emitted around each invocation of a configured `WalletPasses.EventHandler`
callback (`on_pass_added`, `on_pass_removed`, `on_pass_fetched`). The
handler itself runs under the `WalletPasses.EventHandler.TaskSupervisor`,
so these events are emitted from a supervised task, not the Plug request
process.

| Field                  | Keys                                                          |
|------------------------|---------------------------------------------------------------|
| Measurements (`:stop`) | `duration`                                                    |
| Metadata (`:start`)    | `handler`, `callback`                                         |
| Metadata (`:stop`)     | `handler`, `callback`, `status` (`:ok` \| `:error`), and on error: `kind`, `reason` |

Uses manual `:telemetry.execute/3` with an internal `try/rescue/catch`.
**No `:exception` event** — even on handler crashes, a `:stop` event fires
with `status: :error` and the error details captured in metadata. The
crash is also logged via `Logger.error`. This means you can attach a
single `:stop` handler and reliably observe both success and failure.

## Integration patterns

### Minimal handler — log every event

```elixir
defmodule MyApp.WalletTelemetry do
  require Logger

  @events [
    [:wallet_passes, :apple, :build_pass, :stop],
    [:wallet_passes, :apple, :push, :stop],
    [:wallet_passes, :google, :create_object, :stop],
    [:wallet_passes, :google, :update_object, :stop],
    [:wallet_passes, :google, :update_object_state, :stop],
    [:wallet_passes, :google, :save_url, :stop],
    [:wallet_passes, :event_handler, :dispatch, :stop],
  ]

  def attach do
    :telemetry.attach_many(
      "wallet-passes-log",
      @events,
      &__MODULE__.handle/4,
      nil
    )
  end

  def handle(event, measurements, metadata, _config) do
    duration_us =
      System.convert_time_unit(measurements.duration, :native, :microsecond)

    Logger.info("wallet_passes event",
      event: Enum.join(event, "."),
      duration_us: duration_us,
      metadata: metadata
    )
  end
end
```

Call `MyApp.WalletTelemetry.attach/0` from your `Application.start/2` after
the supervision tree starts.

### Metrics via `Telemetry.Metrics`

Define metrics with [`Telemetry.Metrics`](https://hexdocs.pm/telemetry_metrics/)
and feed them to PromEx, `telemetry_metrics_prometheus`,
`telemetry_metrics_statsd`, or any other reporter:

```elixir
import Telemetry.Metrics

[
  summary("wallet_passes.apple.build_pass.stop.duration",
    unit: {:native, :millisecond}
  ),
  summary("wallet_passes.google.update_object_state.stop.duration",
    unit: {:native, :millisecond},
    tags: [:pass_type, :state, :status]
  ),
  counter("wallet_passes.google.create_object.stop", tags: [:status]),
  counter("wallet_passes.event_handler.dispatch.stop",
    tags: [:callback, :status]
  ),
  sum("wallet_passes.apple.push.stop.success_count"),
  sum("wallet_passes.apple.push.stop.error_count"),
]
```

Avoid using `serial_number` or `object_id` as a Prometheus tag — the
cardinality is unbounded. Keep those fields for logging only.

### PromEx and OpenTelemetry

There is no built-in PromEx plugin; define a custom plugin whose
`metrics/1` callback returns the definitions above.

For tracing, [`opentelemetry_telemetry`](https://hex.pm/packages/opentelemetry_telemetry)
turns any `:telemetry.span/3` event triple into an OTel span. Bridge each
prefix that uses span (every event in this guide except `:apple, :push`
and `:event_handler, :dispatch`, which use manual execute).

### Structured logging

If you use a JSON `Logger` backend, the handler above produces queryable
logs. Tagging the request process with `Logger.metadata/1` before a build
lets the serial number propagate to every log line emitted during it:

```elixir
Logger.metadata(serial_number: pass_data.serial_number)
WalletPasses.build_apple_pass(pass_data, visual)
```

## API Reference

`wallet_passes` does not expose any library-specific telemetry API. All
attachment and configuration happens via the standard `:telemetry` module:

- [`:telemetry.attach/4`](https://hexdocs.pm/telemetry/telemetry.html#attach/4)
- [`:telemetry.attach_many/4`](https://hexdocs.pm/telemetry/telemetry.html#attach_many/4)
- [`:telemetry.detach/1`](https://hexdocs.pm/telemetry/telemetry.html#detach/1)
- [`Telemetry.Metrics`](https://hexdocs.pm/telemetry_metrics/)

The events themselves are the contract; the event names and the keys
listed in each table above are stable across minor versions.

See also:

- [Getting Started](getting-started.md)
- [Apple Wallet](apple-wallet.md) — context for `:apple, :build_pass` and `:apple, :push`
- [Google Wallet](google-wallet.md) — context for `:google, :create_object`, `:google, :update_object`, `:google, :save_url`, and `:google, :create_or_update_class`
- [Event Handling & Wallet Presence](event-handling.md) — context for `:event_handler, :dispatch`
- [Pass Lifecycle & Updates](lifecycle.md) — context for `:google, :update_object_state`