Debugging slow LlamaIndex queries with latency traces

Slow RAG pipelines waste tokens and frustrate users. LlamaIndex query latency debugging starts with capturing where time actually goes: retrieval, node postprocessing, prompt assembly, and model inference. Without traces, you are guessing which stage is the bottleneck.

This guide walks through instrumenting a LlamaIndex application with OpenTelemetry so you can see per-stage timings. You will end up with runnable code, a trace you can read, and a repeatable way to verify optimizations.

Step 1: Set up an OpenTelemetry tracer

Install the SDK and a simple exporter. The console exporter is enough to validate locally; swap it for OTLP later to send to Jaeger or Tempo.

pip install opentelemetry-sdk opentelemetry-exporter-console llama-index

Initialize a tracer provider in your entrypoint:

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import SimpleSpanProcessor, ConsoleSpanExporter

provider = TracerProvider()
provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter()))
trace.set_tracer_provider(provider)
tracer = trace.get_tracer("llamaindex.debug")

Keep the tracer reference handy. You will pass it into the LlamaIndex callback handler next.

Step 2: Write a callback handler that emits spans

LlamaIndex exposes a CallbackManager and event types for every internal step. A custom BaseCallbackHandler maps those events to OpenTelemetry spans. The two methods you must implement are on_event_start and on_event_end.

from llama_index.core.callbacks import BaseCallbackHandler, CBEventType, EventPayload
from opentelemetry import trace

class OtelCallbackHandler(BaseCallbackHandler):
    def __init__(self, tracer):
        self._tracer = tracer
        self._spans = {}

    def on_event_start(self, event_type, payload=None, event_id="", parent_id=None, **kwargs):
        parent = self._spans.get(parent_id) if parent_id else None
        span = self._tracer.start_span(event_type.value, parent=parent)
        self._spans[event_id] = span

    def on_event_end(self, event_type, payload=None, event_id="", result=None, **kwargs):
        span = self._spans.pop(event_id, None)
        if not span:
            return
        if payload and EventPayload.QUERY_STR in payload:
            span.set_attribute("query", payload[EventPayload.QUERY_STR])
        if event_type == CBEventType.RETRIEVE and payload:
            nodes = payload.get(EventPayload.NODES, [])
            span.set_attribute("retrieved_nodes", len(nodes))
        if result and hasattr(result, "response"):
            span.set_attribute("response_chars", len(str(result.response)))
        span.end()

The handler starts a span for every LlamaIndex event and closes it when the event finishes. Parent-child relationships are reconstructed using parent_id, which LlamaIndex provides for nested events like QUERY containing RETRIEVE and LLM.

Step 3: Wire the handler into your query engine

Set the callback manager on Settings before building the index or query engine. This ensures every downstream call is instrumented.

from llama_index.core import Settings, VectorStoreIndex, SimpleDirectoryReader
from llama_index.core.callbacks import CallbackManager

documents = SimpleDirectoryReader("data").load_data()
index = VectorStoreIndex.from_documents(documents)

Settings.callback_manager = CallbackManager([OtelCallbackHandler(tracer)])

query_engine = index.as_query_engine(similarity_top_k=8)
response = query_engine.query("What are the late fees on invoices?")
print(response)

Run this script once. You should see span output on stdout, each with a start/end and duration inferred by the exporter.

Step 4: Run a query and inspect the trace

Execute the script against a representative query. The console exporter prints spans in chronological order. A typical trace tree looks like:

QUERY                       12.4s
  RETRIEVE                   1.1s  retrieved_nodes=8
  POSTPROCESS_NODES          0.3s
  LLM                       10.8s

If you do not see nested spans, confirm parent_id is being passed. Some LlamaIndex versions nest LLM under QUERY only when using the high-level query engine; lower-level compositions may emit flat events.

For durable analysis, export to OTLP:

from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
provider.add_span_processor(SimpleSpanProcessor(OTLPSpanExporter()))

Point it at a local Jaeger instance and you get a waterfall view.

Step 5: Identify the latency hotspots

LlamaIndex query latency debugging is mostly about reading the span durations. The event types that matter:

• RETRIEVE: Vector store round-trip. Slow when similarity_top_k is high, the store is remote, or the index is unfiltered.
• POSTPROCESS_NODES: Reranking or node merging. Expensive if you run a cross-encoder on many nodes.
• LLM: Token generation. Dominates when context is large or the model is slow.
• SYNTHESIZE: Often folded into LLM in newer versions, but worth checking if present.

A real example from a production index: RETRIEVE took 800 ms (acceptable), POSTPROCESS_NODES took 2.1 s because a reranker ran on 20 nodes, and LLM took 9 s because the prompt included all 20 node texts. Cutting similarity_top_k to 4 and moving reranking behind a metadata filter dropped total latency to 3.2 s.

Add attributes to your spans to make this obvious. The handler above already records retrieved_nodes and response_chars. Add model name if you use multiple LLMs:

if event_type == CBEventType.LLM and payload:
    span.set_attribute("model", payload.get(EventPayload.MODEL, "unknown"))

Step 6: Optimize and verify with comparative traces

Once you know the hotspot, change one variable and re-run the same query. Common fixes:

• Lower similarity_top_k and add a metadata filter.
• Replace a heavy reranker with a lightweight score threshold.
• Stream LLM output so time-to-first-token is visible, even if total time is similar.
• Use a smaller model for synthesis, or enable prompt caching.

If your LLM calls route through n4n.ai, an OpenAI-compatible endpoint covering 240+ models, you get per-token metering and automatic fallback when a provider degrades. Forwarding provider cache-control hints reduces repeated prompt tokens, which shows up as shorter LLM spans on subsequent queries.

Example of enabling caching with an OpenAI-compatible client:

from openai import OpenAI

client = OpenAI(base_url="https://api.n4n.ai/v1", api_key="YOUR_KEY")
client.chat.completions.create(
    model="anthropic/claude-3.5-sonnet",
    messages=[{"role": "user", "content": large_context}],
    extra_headers={"x-cache-control": "ephemeral"}
)

After the change, run the query again and compare the root QUERY span duration. If you exported to Jaeger, use the diff view or just subtract the printed durations.

Verify success

Success means the root QUERY span dropped to your target, and the child span that was previously dominant is now proportional. A practical verification loop:

1. Capture a baseline trace for three representative queries.
2. Apply one optimization.
3. Capture a new trace for the same queries.
4. Confirm the slow child span shrank and no other span regressed by more than 10%.

If RETRIEVE is still the longest child after lowering top_k, the problem is your vector store latency, not LlamaIndex. Move the store closer, batch embeddings, or pre-filter by partition.

Latency traces turn LlamaIndex query latency debugging from folklore into a measurement problem. Ship the handler once, keep the tracer in your settings, and every slow query becomes a readable report instead of a mystery.