Xqlite.Telemetry (Xqlite v0.12.1)

View Source

:telemetry integration for xqlite.

Strictly opt-in

Telemetry is gated by a compile-time flag. Default: false. When disabled, every emission site in xqlite compiles to a no-op — there are no :telemetry.execute/3 or :telemetry.span/3 calls in the bytecode at all, nothing is timed and no handler runs. Designed for resource-constrained environments (Nerves, embedded, hot loops) where the cost of even an unused :telemetry.execute/3 matters.

To enable, set this in your application's config/config.exs and rebuild xqlite (mix deps.compile xqlite --force):

config :xqlite, :telemetry_enabled, true

Conventions

  • Event names: atom lists prefixed with :xqlite. Sub-systems get their own segment (:hook, :cancel, :transaction, :savepoint). events/0 returns the whole list as data.
  • Spans: every operation that has a clear "start" and "end" follows :telemetry.span/3's convention — :start, :stop, :exception events with a stable :telemetry_span_context reference linking them. xqlite emits the three itself rather than calling :telemetry.span/3, which measures in the VM's native time unit; xqlite measures in nanoseconds.
  • Time units: integer nanoseconds for every time-valued measurement — monotonic_time, system_time, duration, total_duration and elapsed. No _ns suffix on those key names. Counts (rows_returned, total_rows, pages, retries, count) ride in the same map and are not times. Convert to microseconds (/1_000) or milliseconds (/1_000_000) at handler time.
  • Time source: System.monotonic_time(:nanosecond), not :os.system_time/0. Stable across NTP adjustments and clock changes; consumers map to wall-clock at handler time if needed.
  • Identifiers: raw refs (reference()) for connections, tokens, streams. No abstraction layer — consumers map to stable IDs themselves at attach time.
  • Cancellation outcome: an operation that gets cancelled fires its normal :stop event with metadata.error_reason == :operation_cancelled (NOT :exception). A separate [:xqlite, :cancel, :honored] event also fires.

Event surface — operation events (always-on)

These events fire automatically when telemetry is compiled in. No registration needed; just attach a handler with :telemetry.attach/4.

Every span fires the same three events with the same measurements: :start carries %{monotonic_time, system_time}, and :stop and :exception carry %{duration, monotonic_time}. Numbers a span learns while it runs travel in its :stop metadata, not in its measurements. :exception metadata is the start metadata plus kind, reason and stacktrace. All three carry the same telemetry_span_context reference.

Connection lifecycle

[:xqlite, :open, :start | :stop | :exception]
  start metadata: %{path, mode}
  stop metadata:  %{path, mode, result_class, error_reason}

[:xqlite, :close, :start | :stop | :exception]
  start metadata: %{conn, path}
  stop metadata:  %{conn, path}

:mode is one of :file, :memory, :readonly, :memory_readonly, :temp. :result_class is :ok or :error. :error_reason is nil on success or the structured error reason on failure.

Query / Execute

[:xqlite, :query, :start | :stop | :exception]
  start metadata: %{conn, sql, params_count, cancellable?}
  stop metadata:  %{conn, sql, params_count, cancellable?,
                    result_class, error_reason, num_rows, changes}

[:xqlite, :execute, :start | :stop | :exception]
  start metadata: %{conn, sql, params_count, cancellable?}
  stop metadata:  %{conn, sql, params_count, cancellable?,
                    result_class, error_reason, affected_rows}

[:xqlite, :execute_batch, :start | :stop | :exception]
  start metadata: %{conn, sql_batch_size_bytes, cancellable?}
  stop metadata:  %{conn, sql_batch_size_bytes, cancellable?,
                    result_class, error_reason}

[:xqlite, :query_with_changes, :start | :stop | :exception]
  start metadata: %{conn, sql, params_count, cancellable?}
  stop metadata:  %{conn, sql, params_count, cancellable?,
                    result_class, error_reason, num_rows, changes}

[:xqlite, :explain_analyze, :start | :stop | :exception]
  start metadata: %{conn, sql, params_count}
  stop metadata:  %{conn, sql, params_count, result_class,
                    error_reason, wall_time_ns, rows_produced,
                    scan_count}

wall_time_ns is SQLite's own nanosecond measurement of the executed statement (from EXPLAIN ANALYZE). :cancellable? is true iff the operation was invoked through a *_cancellable NIF or Xqlite.query_cancellable/4 and its siblings. changes is sqlite3_changes() read beside the rows; it is nil on error and on the cancellable query path.

Transactions

Transactions span across multiple NIF calls; we emit single events rather than spans because the matching :stop may come from any later commit/rollback at any time.

[:xqlite, :transaction, :begin]
  measurements: %{monotonic_time}
  metadata:     %{conn, mode}

[:xqlite, :transaction, :commit]
  measurements: %{monotonic_time}
  metadata:     %{conn}

[:xqlite, :transaction, :rollback]
  measurements: %{monotonic_time}
  metadata:     %{conn, reason}

[:xqlite, :savepoint, :create | :release | :rollback_to]
  measurements: %{monotonic_time}
  metadata:     %{conn, name}

:mode is :deferred, :immediate, or :exclusive. :reason on rollback is :user_initiated — the only value xqlite emits, since these three events fire from the explicit transaction API.

Streams

[:xqlite, :stream, :open, :start | :stop | :exception]
  start metadata: %{conn, sql, batch_size, type_extensions_count,
                    cancellable?}
  stop metadata:  %{conn, sql, batch_size, type_extensions_count,
                    cancellable?, result_class, error_reason}

[:xqlite, :stream, :fetch]
  measurements: %{monotonic_time, duration, rows_returned}
  metadata:     %{stream_handle, done?}

[:xqlite, :stream, :close]
  measurements: %{monotonic_time, total_duration, total_rows}
  metadata:     %{stream_handle, reason, close_error (only on a
                  failed close)}

The close event's :reason says how the stream ended: :drained when every row was read, :halted when the consumer stopped early, :errored when a fetch failed — in every :on_error mode, the raising one included. It does not describe the closing call itself; when that call fails, the metadata gains :close_error with the reason it gave.

The fetch event fires every batch — potentially thousands of times per stream. The cost is sub-microsecond when no handler is attached and zero when telemetry is disabled at compile time. If you attach a heavy handler, expect proportional cost; consider sampling or a dedicated metrics handler.

Backup, restore, serialize, deserialize

[:xqlite, :backup, :start | :stop | :exception]
  start metadata: %{conn, schema, dest_path}
  stop metadata:  %{conn, schema, dest_path, result_class,
                    error_reason, byte_size}

[:xqlite, :restore, :start | :stop | :exception]
  start metadata: %{conn, schema, src_path}
  stop metadata:  %{conn, schema, src_path, result_class, error_reason}

[:xqlite, :serialize, :start | :stop | :exception]
  start metadata: %{conn, schema}
  stop metadata:  %{conn, schema, result_class, error_reason, byte_size}

[:xqlite, :deserialize, :start | :stop | :exception]
  start metadata: %{conn, schema, read_only?, byte_size}
  stop metadata:  %{conn, schema, read_only?, byte_size,
                    result_class, error_reason}

byte_size is nil on a failed backup or serialize. Xqlite.backup_with_progress/6 reports to a pid instead and emits no telemetry of its own.

WAL checkpoint and extensions

[:xqlite, :wal_checkpoint, :start | :stop | :exception]
  start metadata: %{conn, mode, schema}
  stop metadata:  %{conn, mode, schema, result_class, error_reason,
                    log_pages, checkpointed_pages, busy?}

[:xqlite, :extension, :load, :start | :stop | :exception]
  start metadata: %{conn, path, entry_point}
  stop metadata:  %{conn, path, entry_point, result_class, error_reason}

[:xqlite, :extension, :enable]
  measurements: %{monotonic_time}
  metadata:     %{conn, enabled}

WAL :mode is :passive, :full, :restart, or :truncate. :busy? is true if the checkpoint did not complete because of reader/writer contention. The three checkpoint counters are present only when the checkpoint succeeded.

PRAGMA

[:xqlite, :pragma, :get | :set]
  measurements: %{monotonic_time}
  metadata:     %{conn, name, value (on :set only)}

Cancellation

[:xqlite, :cancel, :token_created]
  measurements: %{monotonic_time}
  metadata:     %{token}

[:xqlite, :cancel, :signalled]
  measurements: %{monotonic_time}
  metadata:     %{token}

[:xqlite, :cancel, :honored]
  measurements: %{monotonic_time}
  metadata:     %{conn, operation, tokens}

:operation is the operation that the cancel signal interrupted: :query, :execute, :execute_batch, :query_with_changes, or :stream_fetch. :tokens is the list of tokens that operation was watching.

Event surface — hook bridge events (opt-in registration)

The hook bridge layer turns multi-subscriber hook deliveries into telemetry events. NOT auto-attached — the user explicitly calls bridge/2 on a connection to wire the hooks they care about.

[:xqlite, :hook, :commit]
  measurements: %{monotonic_time}
  metadata:     %{conn, tag}

[:xqlite, :hook, :rollback]
  measurements: %{monotonic_time}
  metadata:     %{conn, tag}

[:xqlite, :hook, :update]
  measurements: %{monotonic_time}
  metadata:     %{conn, tag, action, db_name, table, rowid}

[:xqlite, :hook, :wal]
  measurements: %{monotonic_time, pages}
  metadata:     %{conn, tag, db_name}

[:xqlite, :hook, :progress]
  measurements: %{monotonic_time, count, elapsed}
  metadata:     %{conn, tag, hook_tag}

[:xqlite, :hook, :busy]
  measurements: %{monotonic_time, retries, elapsed}
  metadata:     %{conn, tag}

[:xqlite, :hook, :log]
  measurements: %{monotonic_time}
  metadata:     %{tag, code, base_code, message}

:tag (in the metadata) is the user-supplied tag from bridge/2 for distinguishing connections in dashboards. :hook_tag, only on the progress event, is the tag passed to Xqlite.register_progress_hook/3. :elapsed is a nanosecond count, converted from the milliseconds SQLite reports.

See bridge/2 and unbridge/1 for the registration API. Bridge is implemented on top of the same multi-subscriber primitives that power direct hook usage — registering the bridge on a connection is independent of any other subscribers, and unbridging never affects them.

Compile-time disabled mode

When :telemetry_enabled is false (the default), the macros in this module expand to no-ops and the underlying operations skip emission entirely. Verify with enabled?/0:

iex> Xqlite.Telemetry.enabled?()
false

In this mode, bridge/2 returns {:error, :telemetry_disabled} rather than silently registering hooks that produce no events.

Reading the source

This module is small on purpose. The three macros (emit/3, span/3 and span_with_stop_metadata/3) are what every call site in lib/xqlite/*.ex invokes. They read the :telemetry_enabled flag at compile time and either expand to :telemetry calls or to direct evaluation of the inner block. The macros live here, not in each caller, so the compile-time check happens in one place; the span bodies expand to run_span/3, which emits the three span events with nanosecond measurements.

Summary

Functions

Bridges per-connection hook deliveries into :telemetry events.

Bridges the global SQLite log hook into :telemetry events.

Emit a single telemetry event.

Returns whether telemetry is compiled in.

Returns every event xqlite can emit, in the order the moduledoc presents them.

Returns the current monotonic time in nanoseconds.

Run block inside a span: a :start event, then a :stop one.

Like span/3 but lets the block return {value, stop_metadata} or {value, extra_measurements, stop_metadata}, so the :stop event can carry numbers and metadata that weren't known at :start.

Tears down a bridge — unregisters every subscribed hook and stops the forwarder GenServer.

Functions

bridge(conn, opts \\ [])

@spec bridge(
  reference(),
  keyword()
) :: {:ok, struct()} | {:error, term()}

Bridges per-connection hook deliveries into :telemetry events.

Subscribes to the requested hooks on conn via the standard register_*_hook API and forwards each delivery as an [:xqlite, :hook, :*] telemetry event. Returns {:ok, %Xqlite.Telemetry.Bridge{}} on success — pass that struct to unbridge/1 to tear down.

Options

  • :hooks — list of hook kinds to subscribe to. Either an explicit list ([:wal, :commit, :rollback, :update, :progress, :busy]) or :all (default) for every per-connection hook.
  • :tag — arbitrary term forwarded as :tag in every [:xqlite, :hook, :*] event's metadata. Useful when one handler receives bridged events from multiple connections.
  • :progress — keyword opts forwarded to register_progress_hook/3 (default every_n: 1000).

Returns {:error, :telemetry_disabled} when telemetry is compile-disabled — the bridge would otherwise install hooks that produce nothing.

Note on busy handling

Busy observation is part of the per-conn bridge: pass hooks: [:busy] (or the default :all) and every contention callback re-emits as [:xqlite, :hook, :busy]. The retry policy is the half that is not bridged — it stays a single slot per connection, set with Xqlite.set_busy_policy/2. See Xqlite.Telemetry.Bridge for the rationale.

bridge_log(opts \\ [])

@spec bridge_log(keyword()) :: {:ok, struct()} | {:error, term()}

Bridges the global SQLite log hook into :telemetry events.

Subscribes to the process-wide log hook and re-emits each diagnostic as [:xqlite, :hook, :log]. Returns {:ok, %Xqlite.Telemetry.Bridge{}} — call unbridge/1 to detach.

Options

  • :tag — arbitrary term forwarded as :tag in event metadata.

emit(event_name, measurements, metadata)

(macro)

Emit a single telemetry event.

Wraps :telemetry.execute/3. When telemetry is compiled out, expands to a no-op that still evaluates the arguments and discards their values.

enabled?()

@spec enabled?() :: boolean()

Returns whether telemetry is compiled in.

Reads the value of :telemetry_enabled at xqlite compile time. Always a constant after compilation; safe to call anywhere.

events()

@spec events() :: [%{name: [atom()], kind: :span | :event}]

Returns every event xqlite can emit, in the order the moduledoc presents them.

Each entry is %{name: [atom()], kind: :span | :event}. A :span entry stands for three event names — its name with :start, :stop and :exception appended. An :event entry is the whole name on its own.

Useful for attaching one handler to everything:

names =
  Enum.flat_map(Xqlite.Telemetry.events(), fn
    %{name: name, kind: :span} ->
      Enum.map([:start, :stop, :exception], &(name ++ [&1]))

    %{name: name, kind: :event} ->
      [name]
  end)

:telemetry.attach_many("my-app-xqlite", names, &MyApp.handle/4, nil)

The list is the one source for the event surface: the moduledoc above, guides/wiring_telemetry.md, and the emission sites in lib/ are all checked against it by the test suite.

monotonic_time()

@spec monotonic_time() :: integer()

Returns the current monotonic time in nanoseconds.

Inlined helper used in metadata maps that record event timestamps. Equivalent to System.monotonic_time(:nanosecond); provided for readability at call sites and for a single canonical source for the rest of xqlite.

span(event_name, metadata, list)

(macro)

Run block inside a span: a :start event, then a :stop one.

The block must evaluate to a value; that value is returned. Both the :start and :stop events carry the supplied metadata. If the block raises, throws or exits, an :exception event fires instead of :stop, with kind, reason, and stacktrace added to the metadata, and the exception re-raises unchanged.

When telemetry is compiled out, the block evaluates directly with no telemetry calls.

span_with_stop_metadata(event_name, start_metadata, list)

(macro)

Like span/3 but lets the block return {value, stop_metadata} or {value, extra_measurements, stop_metadata}, so the :stop event can carry numbers and metadata that weren't known at :start.

With telemetry compiled out there is no event to carry them, so both shapes are unwrapped to their value. The accepted shapes are the same either way: a block that evaluates to anything else fails in both builds.

unbridge(bridge)

@spec unbridge(struct()) :: :ok

Tears down a bridge — unregisters every subscribed hook and stops the forwarder GenServer.