Tracing model calls, tools and retrieval

By the following Monday, Langfuse was running on the back-office server, the OpenTelemetry Collector was forwarding spans, and Sneha could see the bot in Grafana. Meera stopped by with her coffee and asked the only question she cared about.

“Is the brownie thing fixed?”

Arjun hesitated. On Friday he had added a line to CrumbBot’s system prompt: Be extra careful with allergy questions. He had tested it twice and both answers looked fine. “I think so,” he said.

Priya raised an eyebrow. “You think so. Two weeks ago you had one log line. Now you have a tracing system. Let’s replay Nandini’s question twenty times, read what the bot actually read, and find the cause, not a guess.”

Arjun’s first attempt: one decorator at the top

Arjun’s first Langfuse integration took one line. He put @observe() on the chat handler and nothing else.

@observe()
def handle_message(session_id: str, user_id: str, text: str) -> str:
    query = rewrite_query(text)
    chunks = retrieve(query, k=4)
    return generate_answer(text, chunks)

He replayed Nandini’s question. Langfuse showed one trace with one box: input “Hi! Is your fudge brownie nut-free?..”, output “Yes! Our fudge brownie is nut-free…”, duration 3.21 s.

“It’s the log line again,” Priya said, “with a nicer font. Where did the 3.21 seconds go? What did retrieval return? How much did it cost?”

“It doesn’t say.”

“Because you only gave it one camera, at the front door.”

The batch card

Priya walked him over to the window that looks into Crumb’s central kitchen. On every tray rack hung a laminated card. “What’s that?”

“The batch card. Who mixed the batter, which flour lot, oven temperature, time in the oven, who checked it.”

“If a batch of brownies comes out dense, what do you do?”

“Read the card. Oven at 160 instead of 180, or the wrong flour lot. Then you know which step to fix.”

“A trace is a batch card for one request, filled in automatically at every station. Your one decorator is a card that says ‘brownies made, 3.21 seconds’. We need a line per station.”

“Where does it break?”

“A batch always visits the same stations in the same order. An agent decides its own route: sometimes no tools, sometimes three tool calls and four model calls. So the card has to grow as the request goes, which is what nested spans do.”

Building the instrumented CrumbBot, step by step

Here is CrumbBot instrumented properly, built in four steps. It uses Langfuse’s Python SDK from Lesson 2, Chroma from Module 08 and Claude. The knowledge base is a tiny stand-in with five chunks; in production it holds about 4,000.

Step 1: setup and a tiny knowledge base. Each chunk carries metadata saying where it came from. That detail will matter.

# crumbbot_traced.py
# uv add langfuse anthropic chromadb python-dotenv
import re

import anthropic
import chromadb
from dotenv import load_dotenv
from langfuse import get_client, observe, propagate_attributes

load_dotenv()                      # Langfuse and Anthropic keys from .env
langfuse = get_client()
client = anthropic.Anthropic()
MODEL = "claude-opus-5-5"
PROMPT_VERSION = "support-v12"
PRICE_IN, PRICE_OUT = 4 / 1_000_000, 20 / 1_000_000   # $ per token, at the time of writing

db = chromadb.PersistentClient(path="./crumb_db")
kb = db.get_or_create_collection("knowledge", metadata={"hnsw:space": "cosine"})
kb.upsert(
    ids=["recipe-2025-brownie-02", "faq-allergy-01", "blog-2025-08-brownie",
         "allergen-2026-07", "menu-2026-desserts-01"],
    documents=[
        "Chocolate Fudge Brownie (2025 recipe card): dark chocolate, butter, eggs, maida, cocoa. No nuts.",
        "We take allergies seriously. Products containing nuts are labelled in store.",
        "Behind the bake: why our fudge brownie has no nuts (August 2025).",
        "Allergen table from 1 Aug 2026: Walnut Fudge Brownie (formerly Chocolate Fudge Brownie) "
        "CONTAINS TREE NUTS (walnut). Not suitable for nut allergies.",
        "Desserts menu 2026: Walnut Fudge Brownie Rs 120, Eggless Chocolate Cake slice Rs 140.",
    ],
    metadatas=[{"source": "recipe-archive", "status": "archive"},
               {"source": "faq", "status": "current"},
               {"source": "blog", "status": "archive"},
               {"source": "allergen-table", "status": "current"},
               {"source": "menu", "status": "current"}],
)

hnsw:space: cosine tells Chroma to measure closeness by cosine distance (Module 07), so 1 - distance gives a similarity score where higher is closer.

Step 2: retrieval and model calls as spans.

@observe(name="retrieve", as_type="retriever")
def retrieve(query: str, k: int = 4) -> list[dict]:
    hits = kb.query(query_texts=[query], n_results=k)
    return [{"id": i, "score": round(1 - d, 3), "text": doc}          # the span's output
            for i, d, doc in zip(hits["ids"][0], hits["distances"][0], hits["documents"][0])]

@observe(name="claude", as_type="generation")
def call_claude(system: str, messages: list, tools: list | None = None):
    extra = {"tools": tools} if tools else {}
    response = client.messages.create(model=MODEL, max_tokens=500,
                                      system=system, messages=messages, **extra)
    u = response.usage
    langfuse.update_current_generation(
        model=MODEL,
        usage_details={"input": u.input_tokens, "output": u.output_tokens},
        cost_details={"input": u.input_tokens * PRICE_IN, "output": u.output_tokens * PRICE_OUT},
        metadata={"stop_reason": response.stop_reason, "response_id": response.id,
                  "prompt_version": PROMPT_VERSION},
    )
    return response

@observe(name="rewrite_query")
def rewrite_query(text: str) -> str:
    r = call_claude("Rewrite the customer's message as a short search query. Reply with the query only.",
                    [{"role": "user", "content": text}])
    return next(b.text for b in r.content if b.type == "text").strip()

@observe records each function’s arguments as the span’s input and its return value as the output. as_type tells Langfuse what kind of step it is: retriever for a search, generation for a model call, and in step 3, tool. So the retrieve span automatically holds the exact query, k, and every chunk id with its score. The claude generation records model, tokens, cost and, in metadata, the stop reason and prompt version. We pass cost_details ourselves because a tracing tool’s price table can lag behind new models (Lesson 2). If you use prompt caching from Module 21, add Claude’s cache_read_input_tokens to usage_details too, so cached tokens are visible.

Step 3: a tool as a span.

TOOLS = [{"name": "order_status",
          "description": "Look up the delivery status of a Crumb order.",
          "input_schema": {"type": "object", "properties": {"order_id": {"type": "string"}},
                           "required": ["order_id"]}}]

@observe(name="order_status", as_type="tool")
def order_status(order_id: str) -> str:
    return f"{order_id}: out_for_delivery, ETA 20:30"   # stand-in for the real order service

Step 4: the root span, with session, user, masking and the agent loop.

PHONE = re.compile(r"(?:\+91[\s-]?)?[6-9]\d{4}[\s-]?\d{5}")
EMAIL = re.compile(r"[\w.+-]+@[\w-]+\.[\w.]+")

def redact(text: str) -> str:
    return EMAIL.sub("[EMAIL]", PHONE.sub("[PHONE]", text))

SYSTEM = ("You are CrumbBot, Crumb & Co.'s support assistant. Answer only from the context "
          "and cite chunk ids. If the context does not answer the question, say so.")

@observe(name="handle_message", capture_input=False)    # don't record the raw text
def handle_message(session_id: str, user_id: str, text: str) -> dict:
    text = redact(text)                                  # mask before anything is traced
    langfuse.update_current_span(input=text)             # the root's input is the trace's input
    with propagate_attributes(session_id=session_id, user_id=user_id, tags=["support-chat"],
                              metadata={"prompt_version": PROMPT_VERSION}):
        chunks = retrieve(rewrite_query(text))
        context = "\n".join(f"[{c['id']}] {c['text']}" for c in chunks)
        messages = [{"role": "user", "content": f"Context:\n{context}\n\nCustomer: {text}"}]
        for _ in range(5):                               # the agent loop, capped
            response = call_claude(SYSTEM, messages, TOOLS)
            if response.stop_reason != "tool_use":
                break
            messages.append({"role": "assistant", "content": response.content})
            messages.append({"role": "user", "content": [
                {"type": "tool_result", "tool_use_id": b.id, "content": order_status(**b.input)}
                for b in response.content if b.type == "tool_use"]})
        answer = next((b.text for b in response.content if b.type == "text"),
                      "Let me pass this to the team.")
    return {"answer": answer, "trace_id": langfuse.get_current_trace_id()}

if __name__ == "__main__":
    out = handle_message("sess-replay-01", "cust-4412",
                         "Hi! Is your fudge brownie nut-free? My son Aarav has a tree-nut "
                         "allergy and I want 12 for his birthday on Saturday.")
    print(out["answer"], "\ntrace:", out["trace_id"])
    langfuse.flush()                                     # short script: send spans before exit

Three details deserve a closer look. propagate_attributes stamps the session id and user id on the root span and every span created inside its with block, so Langfuse can group Nandini’s three messages and find all traces for customer cust-4412. Call it as early as possible: spans created before it don’t get the fields. get_current_trace_id() returns this request’s trace id; your web endpoint sends it to the chat widget so feedback can be attached later. And capture_input=False plus redact() keeps phone numbers and emails out of the trace.

Library APIs change quickly. If a name has moved, check the docs linked below.

Reading the brownie trace

Arjun replayed Nandini’s exact message twenty times against the production knowledge base. Seventeen answers said the brownie was nut-free. Two said “I’m not sure, please check with the store.” One said it contained walnuts. He opened the first nut-free trace:

flowchart TD
  R["handle_message (sess-replay-01, 3.21 s, $0.0106)"] --> Q["rewrite_query (0.41 s)"]
  R --> S["retrieve (0.10 s, k 4)"]
  S --> S1["1. recipe-2025-brownie-02 (0.86)"]
  S --> S2["2. faq-allergy-01 (0.79)"]
  S --> S3["3. recipe-2025-brownie-05 (0.77)"]
  S --> S4["4. blog-2025-08-brownie (0.74)"]
  R --> G["claude generation (2.65 s, 1,912 in / 96 out)"]

The four leaves are not spans; they are the retrieve span’s output, drawn as leaves so you can see them. The rewrite_query box also holds its own small claude generation, left out to keep the picture readable.

The tree confirmed what Lesson 1 had pieced together by hand, but now with evidence: the query was fudge brownie nut-free tree nut allergy, two of the four chunks were from 2025, and no allergen table. Then Arjun did something the trace made easy. He copied the exact query from the retrieve span and ran it against Chroma with k=10:

Rank	Chunk id	Score	Status
1	recipe-2025-brownie-02	0.86	archive
2	faq-allergy-01	0.79	current
3	recipe-2025-brownie-05	0.77	archive
4	blog-2025-08-brownie	0.74	archive
5	hamper-diwali-2026-03	0.72	current
6	allergen-2026-07	0.71	current

There it was. The current allergen table ranked sixth, 0.15 below last year’s recipe card. With k=4, it never reached the model.

Why did old chunks win? The customer wrote “fudge brownie”. Last year’s documents say “Chocolate Fudge Brownie” over and over. This year’s allergen table says “Walnut Fudge Brownie (formerly Chocolate Fudge Brownie)”, a closer match in fact but a weaker one in wording. And when the recipe archive was indexed in Module 09, it went into the same collection as the live menu, with no marker saying which was current.

Then Arjun opened the one trace where the bot got it right. Its rewrite_query output was walnut fudge brownie allergens. The model had added “walnut” on its own, and with that word the allergen table ranked second. Same message, different rewrite, different path. Non-determinism, caught in the act.

“So the model was innocent,” Meera said, when he showed her.

“Faithful,” Priya said. “It answered from what it was given. Retrieval gave it the wrong page. And Arjun’s Friday prompt line couldn’t have fixed that. You can’t be careful with a fact you were never shown.”

What each request costs, and where its time goes

With every model call carrying tokens and cost, Langfuse adds them up per trace. Two typical CrumbBot traces, at $4and$20 per million input and output tokens:

The brownie trace (no tools): rewrite 180 in / 14 out = $0.00100;answer1,912in/96out=$0.00957. Total $0.0106, about ₹0.93.

An order-status trace, “Where is my order CR-58213?”, which loops once through the tool:

Span	Duration	Tokens in / out	Cost
handle_message (root)	5.62 s		$0.0213 (₹1.88)
rewrite_query generation	0.38 s	170 / 12	$0.00092
retrieve	0.09 s
claude generation 1, stop reason tool_use	1.86 s	2,050 / 58	$0.00936
order_status	0.84 s
claude generation 2, stop reason end_turn	2.41 s	2,210 / 110	$0.01104

Langfuse draws this as a latency waterfall: one bar per span, placed on a shared timeline, so you see what ran when and what waited. The two generations take 4.27 s, 76% of the request. The tool takes 0.84 s, 15%, almost all of it waiting on the delivery partner’s API.

Across a day, Langfuse’s dashboard showed 1,800 traces at an average of about $0.015,roughly$27 or ₹2,400 a day, with order-status questions costing twice as much as menu questions because of the second model call.

Sessions and feedback

Clicking Nandini’s session showed her three messages in order: the brownie question, the Baner pickup question and “Thank you!”. Sessions matter because many failures only make sense in context. “Yes, that one” is unreadable as a lone trace.

The chat widget already had thumbs-up and thumbs-down buttons that nobody read. Arjun wired them to Langfuse through a small backend endpoint. The widget sends the trace id it received with the answer, never the Langfuse keys:

def record_feedback(trace_id: str, thumbs_up: bool, comment: str = "") -> None:
    langfuse.create_score(name="user_feedback", value=1 if thumbs_up else 0,
                          trace_id=trace_id, comment=comment)

A score is a number or label attached to a trace. Now every thumbs-down appears on its trace, and a saved filter, user_feedback = 0, lists the bad ones each morning. In its first week: 1,800 traces a day, about 2% with any feedback at all, and 11 thumbs-down. Arjun read all 11. Four were wrong answers, three were slow replies, and four were customers annoyed that the bot couldn’t change a delivery address.

Sampling, flushing and other production details

Sampling. At Crumb’s volume, keeping every trace takes under a gigabyte a month, so they keep 100% for 30 days. Larger apps sample: they keep a fraction of traces. The Langfuse SDK has a sample-rate setting for this, and an OpenTelemetry Collector can sample too.

Flushing. In the FastAPI app (Module 05), spans go out in the background, and Arjun added langfuse.flush() to the app’s shutdown hook so a redeploy doesn’t drop the last few seconds of spans. Scripts, scheduled jobs and notebooks call flush() before they end.

Too many spans. Decorate the steps a human would want on the batch card: requests, retrievals, model calls, tool calls. Don’t decorate a helper that formats a chunk and runs 40 times per request; the tree turns into noise.

The fix, and proving it

Arjun’s first idea was k=10. Priya did the maths with him: six more chunks at about 120 tokens each is 720 extra input tokens, $0.0029 more per request, a 27% cost increase. And it only works until the next stale chunk ranks eleventh. The real problem was that retrieval could see archived documents at all.

They made two changes in retrieve:

ALLERGY_WORDS = ("allerg", "nut", "egg", "gluten", "dairy", "lactose")

@observe(name="retrieve", as_type="retriever")
def retrieve(query: str, k: int = 4) -> list[dict]:
    hits = kb.query(query_texts=[query], n_results=k,
                    where={"status": "current"})                 # fix 1: never search the archive
    chunks = [{"id": i, "score": round(1 - d, 3), "text": doc}
              for i, d, doc in zip(hits["ids"][0], hits["distances"][0], hits["documents"][0])]
    if any(w in query.lower() for w in ALLERGY_WORDS):           # fix 2: pin the allergen table
        table = kb.get(where={"source": "allergen-table"})
        seen = {c["id"] for c in chunks}
        for i, doc in zip(table["ids"], table["documents"]):
            if i not in seen:
                chunks.insert(0, {"id": i, "score": None, "text": doc, "pinned": True})
    return chunks

Fix 1 is a metadata filter: Chroma only searches chunks whose metadata says status: current. The recipe archive stays useful for the bakers’ internal assistant, but customers never see it. Fix 2 pins a source: for any query that mentions allergy words, the current allergen table is always in the context, whatever its score.

Then they proved it the same way they found it. Twenty replays of Nandini’s message: twenty answers saying the Walnut Fudge Brownie contains walnuts and isn’t suitable for a tree-nut allergy, and suggesting she call the store about nut-free options. The new trace’s retrieve span showed allergen-2026-07 at the top (pinned: true), then menu-2026-desserts-01 at 0.81. No 2025 chunks. Input tokens went from 1,912 to 2,050 and the trace cost from $0.0106to$0.0112, about ₹0.98. Five paise more, for an answer that is right.

Arjun removed his Friday prompt line. It had never been the fix.

Try it yourself

1. Run crumbbot_traced.py and open the trace in Langfuse. Check that the retrieve span’s output lists chunk ids and scores, and that the root shows session sess-replay-01 and user cust-4412.
2. Call handle_message with a message containing “call me on 98220 41763”. Confirm the trace shows [PHONE] everywhere, including inside the claude generation’s input.
3. Add record_feedback(out["trace_id"], thumbs_up=False, comment="test") before flush(), and find the score on the trace.
4. Swap in the fixed retrieve and run the brownie message again.

Expected result. Your toy index has five chunks, so scores will differ from production, and the old version may or may not rank the archive first. After the fix, the retrieve output starts with allergen-2026-07 (marked pinned: true if the search itself didn’t find it) and contains no chunk with status: archive. The answer says the brownie contains walnuts.

Common mistakes

• One decorator at the top. You get a pretty log line. Span every retrieval, model call and tool call.
• Recording chunk text without ids and scores. You can’t find the source document or tell a clear win from a near tie.
• Masking after capture. Decorators record arguments on entry. Redact before the data reaches any observed function.
• Random sampling for soft failures. The bad trace is gone before anyone complains. Keep everything, or keep a cheap record of everything.
• Fixing by prompt when the trace says retrieval. Read the tree first. Fix the step that failed, then prove it with a replay.

Recap

• Instrument every step: the root request (session, user, prompt version), retrieval (query, k, chunk ids, scores), model calls (model, tokens, cost, stop reason) and tools (arguments, results, latency).
• Read the tree top-down to find the first step that went wrong; replay the recorded inputs to dig deeper.
• Traces give cost per request and a latency waterfall, so you optimise the slowest span, not a guess.
• Sessions group a conversation; feedback scores pin customer complaints to exact traces.
• Mask before capture, flush before exit, and be careful with sampling: soft failures are invisible at sampling time.

Arjun explained it to Meera that afternoon. “The bot’s search was reading last year’s recipe card, where the brownie had no nuts. The current allergen table came sixth, and the bot only reads the top four. Now the search ignores old documents, and for any allergy question it always reads the allergen table. I replayed the question twenty times. Twenty right answers, and five paise more per answer.”

Meera thought for a moment. “Good. But we found this because Nandini phoned the store. Most people wouldn’t. How do we find the next one before a customer does?”

Priya was already smiling. “We have 1,800 traces a day sitting in Langfuse. We start by reading them, properly, and we turn what we find into tests the bot has to pass before every change.” That is Module 23: evaluations.

Go deeper

• Langfuse documentation (Python SDK, sessions, scores, masking, sampling): https://langfuse.com/docs
• OpenTelemetry GenAI semantic conventions, including agent and tool spans: https://opentelemetry.io/docs/specs/semconv/gen-ai/
• Chroma documentation, for metadata filters with where: https://docs.trychroma.com
• Building effective agents (why simple, observable agent loops win): https://www.anthropic.com/research/building-effective-agents