Telemetry events emitted by Arcana.

Arcana uses the standard :telemetry library to emit events for observability. You can attach handlers to these events for logging, metrics, or tracing.

Events

All events are emitted using :telemetry.span/3, which automatically generates :start, :stop, and :exception events.

Ingest Events

• [:arcana, :ingest, :start] - Emitted when document ingestion begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{text: String.t(), repo: module(), collection: String.t()}

• [:arcana, :ingest, :stop] - Emitted when document ingestion completes.

  • Measurement: %{duration: integer}
  • Metadata: %{document: Document.t(), chunk_count: integer}

• [:arcana, :ingest, :exception] - Emitted when document ingestion fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

Search Events

• [:arcana, :search, :start] - Emitted when a search query begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{query: String.t(), repo: module(), mode: atom(), limit: integer}

• [:arcana, :search, :stop] - Emitted when a search query completes.

  • Measurement: %{duration: integer}
  • Metadata: %{results: list(), result_count: integer}

• [:arcana, :search, :exception] - Emitted when a search query fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

Ask Events (RAG)

• [:arcana, :ask, :start] - Emitted when a RAG question begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{question: String.t(), repo: module()}

• [:arcana, :ask, :stop] - Emitted when a RAG question completes.

  • Measurement: %{duration: integer}
  • Metadata: %{answer: String.t(), context_count: integer}

• [:arcana, :ask, :exception] - Emitted when a RAG question fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

Embed Events

• [:arcana, :embed, :start] - Emitted when embedding generation begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{text: String.t()}

• [:arcana, :embed, :stop] - Emitted when embedding generation completes.

  • Measurement: %{duration: integer}
  • Metadata: %{dimensions: integer}

• [:arcana, :embed, :exception] - Emitted when embedding generation fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

LLM Events

• [:arcana, :llm, :complete, :start] - Emitted when an LLM call begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{model: String.t(), prompt_length: integer, context_count: integer}

• [:arcana, :llm, :complete, :stop] - Emitted when an LLM call completes.

  • Measurement: %{duration: integer}
  • Metadata: %{success: boolean, response_length: integer} or %{success: false, error: String.t()}

• [:arcana, :llm, :complete, :exception] - Emitted when an LLM call fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

Agent Pipeline Events

Each step in the Agent pipeline emits :start, :stop, and :exception events:

• [:arcana, :agent, :rewrite, :*] - Query rewriting step.

  • Stop metadata: %{query: String.t()}

• [:arcana, :agent, :select, :*] - Collection selection step.

  • Stop metadata: %{selected: [String.t()]}

• [:arcana, :agent, :expand, :*] - Query expansion step.

  • Stop metadata: %{expanded_query: String.t()}

• [:arcana, :agent, :decompose, :*] - Question decomposition step.

  • Stop metadata: %{sub_question_count: integer}

• [:arcana, :agent, :search, :*] - Vector search step.

  • Stop metadata: %{total_chunks: integer}

• [:arcana, :agent, :rerank, :*] - Chunk reranking step.

  • Stop metadata: %{kept: integer, original: integer}

• [:arcana, :agent, :answer, :*] - Answer generation step.

  • Stop metadata: %{}

• [:arcana, :agent, :self_correct, :*] - Self-correction iteration.

  • Stop metadata: %{attempt: integer}

GraphRAG Events

When using GraphRAG features (graph: true), these events are emitted:

• [:arcana, :graph, :build, :start] - Emitted when graph building begins during ingest.

  • Measurement: %{system_time: integer}
  • Metadata: %{chunk_count: integer, collection: String.t()}

• [:arcana, :graph, :build, :stop] - Emitted when graph building completes.

  • Measurement: %{duration: integer}
  • Metadata: %{entity_count: integer, relationship_count: integer}

• [:arcana, :graph, :build, :exception] - Emitted when graph building fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

• [:arcana, :graph, :search, :start] - Emitted when graph-enhanced search begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{query: String.t(), entity_count: integer}

• [:arcana, :graph, :search, :stop] - Emitted when graph-enhanced search completes.

  • Measurement: %{duration: integer}
  • Metadata: %{graph_result_count: integer, combined_count: integer}

• [:arcana, :graph, :search, :exception] - Emitted when graph-enhanced search fails.

  • Measurement: %{duration: integer}
  • Metadata: %{kind: atom(), reason: term(), stacktrace: list()}

• [:arcana, :graph, :ner, :start] - Emitted when NER entity extraction begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{text: String.t()}

• [:arcana, :graph, :ner, :stop] - Emitted when NER entity extraction completes.

  • Measurement: %{duration: integer}
  • Metadata: %{entity_count: integer}

• [:arcana, :graph, :relationship_extraction, :start] - Emitted when relationship extraction begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{text: String.t()}

• [:arcana, :graph, :relationship_extraction, :stop] - Emitted when relationship extraction completes.

  • Measurement: %{duration: integer}
  • Metadata: %{relationship_count: integer}

• [:arcana, :graph, :community_detection, :start] - Emitted when community detection begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{entity_count: integer}

• [:arcana, :graph, :community_detection, :stop] - Emitted when community detection completes.

  • Measurement: %{duration: integer}
  • Metadata: %{community_count: integer}

• [:arcana, :graph, :community_summary, :start] - Emitted when community summarization begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{entity_count: integer}

• [:arcana, :graph, :community_summary, :stop] - Emitted when community summarization completes.

  • Measurement: %{duration: integer}
  • Metadata: %{summary_length: integer}

VectorStore Events

• [:arcana, :vector_store, :store, :start] - Emitted when storing a vector.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection: String.t(), id: String.t()}

• [:arcana, :vector_store, :store, :stop] - Emitted when vector storage completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

• [:arcana, :vector_store, :search, :start] - Emitted when vector search begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection: String.t(), limit: integer}

• [:arcana, :vector_store, :search, :stop] - Emitted when vector search completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom(), result_count: integer}

• [:arcana, :vector_store, :search_text, :start] - Emitted when fulltext search begins.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection: String.t(), query: String.t(), limit: integer}

• [:arcana, :vector_store, :search_text, :stop] - Emitted when fulltext search completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom(), result_count: integer}

• [:arcana, :vector_store, :delete, :start] - Emitted when deleting a vector.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection: String.t(), id: String.t()}

• [:arcana, :vector_store, :delete, :stop] - Emitted when vector deletion completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

• [:arcana, :vector_store, :clear, :start] - Emitted when clearing a collection.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection: String.t()}

• [:arcana, :vector_store, :clear, :stop] - Emitted when collection clearing completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

GraphStore Events

• [:arcana, :graph_store, :persist_entities, :start] - Emitted when persisting entities.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection_id: String.t(), entity_count: integer}

• [:arcana, :graph_store, :persist_entities, :stop] - Emitted when entity persistence completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

• [:arcana, :graph_store, :persist_relationships, :start] - Emitted when persisting relationships.

  • Measurement: %{system_time: integer}
  • Metadata: %{relationship_count: integer}

• [:arcana, :graph_store, :persist_relationships, :stop] - Emitted when relationship persistence completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

• [:arcana, :graph_store, :persist_mentions, :start] - Emitted when persisting mentions.

  • Measurement: %{system_time: integer}
  • Metadata: %{mention_count: integer}

• [:arcana, :graph_store, :persist_mentions, :stop] - Emitted when mention persistence completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

• [:arcana, :graph_store, :search, :start] - Emitted when searching graph store.

  • Measurement: %{system_time: integer}
  • Metadata: %{entity_count: integer}

• [:arcana, :graph_store, :search, :stop] - Emitted when graph search completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom(), result_count: integer}

• [:arcana, :graph_store, :delete_by_chunks, :start] - Emitted when deleting by chunks.

  • Measurement: %{system_time: integer}
  • Metadata: %{chunk_count: integer}

• [:arcana, :graph_store, :delete_by_chunks, :stop] - Emitted when chunk deletion completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

• [:arcana, :graph_store, :delete_by_collection, :start] - Emitted when deleting by collection.

  • Measurement: %{system_time: integer}
  • Metadata: %{collection_id: String.t()}

• [:arcana, :graph_store, :delete_by_collection, :stop] - Emitted when collection deletion completes.

  • Measurement: %{duration: integer}
  • Metadata: %{backend: atom()}

Quick Start with Built-in Logger

For quick setup, use the built-in logger:

# In your application's start/2
Arcana.Telemetry.Logger.attach()

This logs all events with timing info. See Arcana.Telemetry.Logger for options.

Custom Handler

For custom handling, attach your own handler:

defmodule MyApp.ArcanaLogger do
  require Logger

  def setup do
    events = [
      [:arcana, :ingest, :stop],
      [:arcana, :search, :stop],
      [:arcana, :ask, :stop],
      [:arcana, :embed, :stop]
    ]

    :telemetry.attach_many("arcana-logger", events, &handle_event/4, nil)
  end

  def handle_event([:arcana, :ingest, :stop], measurements, metadata, _config) do
    Logger.info("Ingested document #{metadata.document.id} with #{metadata.chunk_count} chunks in #{format_duration(measurements.duration)}")
  end

  def handle_event([:arcana, :search, :stop], measurements, metadata, _config) do
    Logger.info("Search returned #{metadata.result_count} results in #{format_duration(measurements.duration)}")
  end

  def handle_event([:arcana, :ask, :stop], measurements, metadata, _config) do
    Logger.info("RAG answered with #{metadata.context_count} context chunks in #{format_duration(measurements.duration)}")
  end

  def handle_event([:arcana, :embed, :stop], measurements, _metadata, _config) do
    Logger.debug("Generated embedding in #{format_duration(measurements.duration)}")
  end

  defp format_duration(duration) do
    duration
    |> System.convert_time_unit(:native, :millisecond)
    |> then(&"#{&1}ms")
  end
end

Then call MyApp.ArcanaLogger.setup() in your application startup.

Integration with Metrics Libraries

These telemetry events work with metrics libraries like:

• telemetry_metrics - Define metrics based on these events
• telemetry_poller - Periodically report metrics
• prom_ex - Export to Prometheus

Example with telemetry_metrics:

defmodule MyApp.Metrics do
  import Telemetry.Metrics

  def metrics do
    [
      counter("arcana.ingest.stop.duration", unit: {:native, :millisecond}),
      counter("arcana.search.stop.duration", unit: {:native, :millisecond}),
      summary("arcana.search.stop.result_count"),
      distribution("arcana.embed.stop.duration", unit: {:native, :millisecond})
    ]
  end
end