PHASE 11Advanced ~23 min· topic 3 of 8

Topic 11.3

Tracing LLM Calls

In one line

A trace shows one request as a tree of timed steps: retrieval, model calls, tools. It answers where the time went and links the services a request crosses. OpenTelemetry is the standard way to produce traces.

Think of it like this

A parcel tracking page. It lists each stop (warehouse, truck, sorting centre, your street) with the time spent at each. When the parcel is late you do not guess: you see that it sat 30 hours at the sorting centre. A trace is the tracking page for one request in your app.

Words you'll meet

New words in this topic, in plain English. Come back here whenever one feels fuzzy.

Trace: All the timed steps (spans) of one request, tied together by a trace id.
Span: One timed step with a name, start, end, parent and attributes.
Trace id: The id shared by every span of one request.
Self time: A span's own time: its total minus the time of its children.
Attribute: A key-value detail attached to a span, such as the model name or token count.
Context propagation: Passing the trace id and parent span id to another service, usually in the traceparent header.
OpenTelemetry: The open standard and libraries for producing and exporting traces, metrics and logs.
Semantic conventions: Agreed names for attributes, so tools from different vendors understand each other.

Step by step

01Step 1: one request, several steps

The request retrieves 3 chunks, calls the model, calls a tool and calls the model again. Without a trace you only know the total. The goal is to record each step's start and end.

02Step 2: a tracer with a counter and a clock

start(name) creates a span with the next id, the current top of the stack as its parent, and the current clock as its start. end() pops the stack and stamps the end. wait(ms) moves the simulated clock. Nesting calls to start and end makes the tree.

tracer.pywhole filepython

def start(self, name):
    parent = self.stack[-1]["id"] if self.stack else 0
    span = {"id": self.next_id, "parent": parent, "name": name, "start": self.clock_ms}
    self.next_id += 1
    self.stack.append(span)
    self.spans.append(span)

03Step 3: print the tree

The depth of a span is its parent's depth plus one. Indenting by depth prints the request with the model calls and the tool as children. The two model calls (620 + 410 ms) are most of the 1,255 ms.

Step 3: print the treediagram

Rendering diagram…

04Step 4: pass the trace to the next service

The gateway builds a traceparent header from the trace id and its span id. The worker parses it and starts its own span with that parent, so both services appear in one trace. The second example does this with counter ids and prints the header with the right zero padding.

05Step 5: find where the time really went

Self time shows what each span did itself. In the example the gateway span lasts 900 ms, but 500 ms of that is the worker, so its self time is 400 ms. That is where to look first if you want to speed up the gateway.

06Step 6: use a real library

The hand-made tracer shows the idea. In production use OpenTelemetry: the SDK (the ready-made library) creates ids and clocks, propagates context across HTTP calls and batches spans. It exports them to a collector (a small service that receives spans and forwards them) or straight to a backend (the tool that stores and shows them). The code block below shows a model call wrapped in a real span in all three languages. Hectal's Observability course (/observability) covers collectors and backends.

Try it yourself

1
Add a span
In handle_request, add a postprocess span of 30 ms between the second model call and the end of the request. Predict the new request total before you run.
2
Make a parent with large self time
Add t.wait(200) directly inside the request span, outside any child. What is the request's self time now, and what would that tell you in a real trace?
3
Read a header
In the second example change the trace id to 255. What do the 32 hex digits look like? Why are they padded with zeros?

Code & diagrams

A tracer built by hand New tab

Ids come from a counter and time from a simulated clock, so the tree is the same every run. A real tracer reads the real clock and generates random ids.

Expected output

span-1 request 1255 ms
  span-2 retrieval 45 ms [3 chunks]
  span-3 model_call 620 ms [tokens_in=1450]
  span-4 tool search_orders 180 ms [status=ok]
  span-5 model_call 410 ms [tokens_in=1710]

Trace context across two services, and self time New tab

The traceparent header is version-traceid-spanid-flags. Here the ids are counters, so the zero padding is easy to see.

Expected output

header sent:   00-00000000000000000000000000000007-0000000000000001-01
worker joined trace 7 as span 2, child of span 1
gateway: total 900 ms, self 400 ms
worker: total 500 ms, self 500 ms

The same span with the real OpenTelemetry SDKpython

Not run here: needs the packages and your own GROQ_API_KEY. Span creation follows the OpenTelemetry language docs. The gen_ai.* names are the GenAI conventions, status Development (open-telemetry/semantic-conventions-genai): check the current page before copying them.

# pip install openai opentelemetry-sdk
import os

from openai import OpenAI
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import ConsoleSpanExporter, SimpleSpanProcessor
from opentelemetry.trace import SpanKind, Status, StatusCode

# 1. Set up the SDK once at start-up: spans go to the console here, to a collector in production.
provider = TracerProvider()
provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter()))
trace.set_tracer_provider(provider)
tracer = trace.get_tracer("my-llm-app")

client = OpenAI(base_url="https://api.groq.com/openai/v1", api_key=os.environ["GROQ_API_KEY"])
MODEL = "openai/gpt-oss-20b"

# 2. One span per model call, named "{operation} {model}" as the GenAI conventions suggest.
with tracer.start_as_current_span(f"chat {MODEL}", kind=SpanKind.CLIENT) as span:
    span.set_attribute("gen_ai.operation.name", "chat")
    span.set_attribute("gen_ai.provider.name", "groq")
    span.set_attribute("gen_ai.request.model", MODEL)
    try:
        reply = client.chat.completions.create(
            model=MODEL, max_tokens=300, messages=[{"role": "user", "content": "Say hello in five words."}]
        )
        span.set_attribute("gen_ai.usage.input_tokens", reply.usage.prompt_tokens)
        span.set_attribute("gen_ai.usage.output_tokens", reply.usage.completion_tokens)
        span.set_attribute("gen_ai.response.finish_reasons", [reply.choices[0].finish_reason])
    except Exception as exc:
        span.record_exception(exc)
        span.set_attribute("error.type", type(exc).__name__)   # a low-cardinality error class
        span.set_status(Status(StatusCode.ERROR))
        raise

Break it on purpose

Errors are the best teachers. Make each change, read the error, guess what went wrong, then reveal the answer.

Break #1

Forget to end a span

In handle_request, delete the t.end() after the retrieval step's t.wait(45).

terminal

$ Run

── what you'll see ──

span-1 request 0 ms

span-2 retrieval 1255 ms [3 chunks]

span-3 model_call 620 ms [tokens_in=1450]

span-4 tool search_orders 180 ms [status=ok]

span-5 model_call 410 ms [tokens_in=1710]

Myth vs fact

Myth

Tracing is only for microservices.

Fact

A single process with retrieval, a model, tools and a second model call already benefits: the tree shows which step is slow.

Myth

A trace needs the prompt text to be useful.

Fact

Names, durations, token counts and ids are what a trace is for. Text is an opt-in extra with privacy cost.

Myth

OpenTelemetry's GenAI attribute names are fixed.

Fact

They are marked Development in the release checked here and have changed between versions. Pin the version and read the current page.

Pro corner

Extra depth for experienced readers. New to this? Skip it for now and come back later.

▸
Sample traces smartly: keep a small share of normal traces, but keep every trace that errored or was slower than a threshold (tail-based sampling in a collector). Slow and failed traces are the ones you will look at.
▸
Record time to first token as an event or attribute on the model span for streamed calls, so a trace can separate waiting for the first token from the length of the answer (Topic 11.4).
▸
Add the request id and prompt version as span attributes (the GenAI conventions also define gen_ai.prompt.version, still in Development) and put the trace id in your log lines. One click from a slow trace to its log lines is the main payoff of having both.

Remember this

1
Why this exists. An LLM request is rarely one call. A real request retrieves documents, calls the model, maybe calls a tool, and calls the model again with the tool result. When the user waits 1.3 seconds, a metric tells you that it was slow, but not which step. A trace tells you: retrieval 45 ms, first model call 620 ms, tool 180 ms, second model call 410 ms. The model calls are the cost; the retrieval is not the problem.
2
Spans and trace ids. A span is one timed step. It has a name, a start time, an end time, a parent span (the step that started it) and attributes (key-value details such as the model name and token counts). A trace is all the spans of one request, tied together by a shared trace id. The top span (the whole request) has no parent; every other span points to its parent, which is how the tree is rebuilt. The first example builds a tracer by hand: ids come from a counter, time comes from a simulated clock, and it prints the tree.
3
Total time and self time. A span's total time includes its children. Its self time is the total minus the children's time: the time spent in the step itself. A request span of 1,255 ms whose children add up to 1,255 ms has self time 0. When the self time of a parent is large, the time went into code that is not traced (parsing, waiting for a lock), which is a clue that a span is missing. The second example computes self time.
4
Across services. If your gateway calls a worker service, the worker must know which trace it belongs to. The caller sends a trace context header, W3C traceparent: 00-<trace id>-<parent span id>-<flags> (version, 32 hex digits, 16 hex digits, flags). The worker reads it and creates its spans as children of that parent with the same trace id. Real libraries do this for you for common HTTP clients; you pass it by hand for queues and custom transports.
5
LLM-specific spans. Make one span per step that can be slow or costly: retrieval (with the number of chunks), model_call (model name, input tokens, output tokens, finish reason), tool (tool name, status). Put identifying details in attributes, not in the span name, so the names stay few and groupable. For agents (a coming Hectal course) the same idea nests: an agent span with a span per reasoning step.
6
OpenTelemetry and its generative-AI conventions. OpenTelemetry (OTel) is the open standard and set of libraries for producing traces, metrics and logs and sending them to any backend. It also defines semantic conventions: agreed attribute names. For model calls, the GenAI conventions say the span name SHOULD be {gen_ai.operation.name} {gen_ai.request.model} (for example chat openai/gpt-oss-20b). The span kind SHOULD be CLIENT (it MAY be INTERNAL for a model running in the same process). The attributes include gen_ai.operation.name and gen_ai.provider.name (both required), gen_ai.request.model, gen_ai.usage.input_tokens, gen_ai.usage.output_tokens and gen_ai.response.finish_reasons. When the call ends in an error, the standard error.type attribute is also expected. Status check: the OpenTelemetry site no longer hosts these pages. They moved to the repository open-telemetry/semantic-conventions-genai, whose pages say Status: Development, meaning not stable. Names have changed between versions, so pin your instrumentation version and read the current page before relying on a name.
7
Content is opt-in. The conventions define attributes for the actual messages (gen_ai.input.messages, gen_ai.output.messages, gen_ai.system_instructions) and say instrumentations should not capture them by default but offer an option. That matches Topic 11.2: put sizes, ids and token counts in spans by default, and add text only deliberately, redacted and sampled.

Explain it without notes

What is a span, and how does a set of spans become a trace?

What is the difference between a span's total time and its self time, and why does it matter?

How does a second service join the trace of the first one?

What should and should not go into span attributes of a model call?

Practice

Write self_times(spans) for spans given as (id, parent, name, start, end) that returns a list of "name self_ms" strings in input order. Self time is total minus the total of direct children.

Write parse_traceparent(header) that returns (trace_id, span_id) as integers, and raises ValueError if the header does not have exactly four parts or the trace id is all zeros.

Trade-offs

↔
More spans give a finer picture and more storage and overhead; trace the steps that can be slow or costly, not every function.
↔
Capturing message text in spans helps debugging and adds privacy risk; keep it off by default.
↔
Using the OpenTelemetry GenAI names makes tools understand your data, but they are still in Development, so expect changes.

Done when you can

Done when you can explain span, parent, trace id and attribute.
Done when you can read a trace tree and compute self time.
Done when you can describe how the traceparent header joins two services.
Done when you can wrap a model call in a real OpenTelemetry span in one language.
Done when you can say what the GenAI conventions' status is and what should stay out of attributes.

Command Palette

Words you'll meet

Step by step

01Step 1: one request, several steps

02Step 2: a tracer with a counter and a clock

03Step 3: print the tree

04Step 4: pass the trace to the next service

05Step 5: find where the time really went

06Step 6: use a real library

Try it yourself

Add a span

Make a parent with large self time

Read a header

Code & diagrams

Break it on purpose

Forget to end a span

Myth vs fact

Pro corner

Remember this

Explain it without notes

Practice

Trade-offs

Done when you can