Lesson 5.3 · LangSmith & Tooling

Reading a Trace

A trace is only useful if you can read it. Walk through the helpdesk agent’s real trace: the tree of runs, which step took the time, how many tokens each model call used, exactly what the model saw - and why the same question took 10.8 seconds once and 5.7 the next time.

observability

What you will be able to do

Read a trace as a tree: root run, child runs, run types
Find where the time goes, and why
Read token counts per model call
Open one model run and see exactly what the model saw and answered
Compare two traces of the same question
Find the things LangSmith shows that our runs contained: tags, metadata, errors

The idea, in plain English

Lesson 5.2 sent the helpdesk agent’s runs to LangSmith. In the LangSmith app you click a trace and see a tree on the left and the details of the selected run on the right. This lesson teaches you to read that tree - what each line means, and where to look for each kind of problem.

To be sure every number is real, we read the same data the app shows: the runs our agent sent (captured in Lesson 5.2), printed as a tree by a short script. In the LangSmith app you will see the same names, types, times and tokens.

langsmith 0.14.7, LangGraph 1.2.14, llama3 on Ollama.

Worked example: Two real traces of "Should I bring an umbrella in Mumbai, and what is 12 * 8?" - one with a cold model (10.80 s), one warm (5.73 s) - read step by step.

workflowReading the umbrella tracestep 1 / 4

LangGraph

the whole run - 10.80 s

agent #1

6.07 s

agent #2

1.02 s

agent #3

3.68 s

ChatOllama

91 in / 16 out

ChatOllama

123 in / 69 out

React Flow

1 - What happened?

The root is the whole run. Its children, top to bottom, are the steps in order: agent, tools, agent, tools, agent.

agent steps

tool steps

total

10.80 s

The real trace, read in four questions. Cold model, 10.80 s in total.

Words you will see in this lesson

The words on a LangSmith trace page.

Small dictionary

Root runThe top of the tree: the whole run of your app.

Child runA step inside another run, shown indented under it.

run_typeWhat a run is: chain (a step or graph), llm (a model call), tool, parser, retriever...

LatencyHow long a run took, from start to end.

Tokens in / outHow much text the model read and wrote (Lesson 5.6).

Cold startThe first call after the model was not in memory - it must load first.

An everyday example: a delivery tracking page

A parcel tracking page lists every stop: picked up, sorting centre, out for delivery, delivered - each with a time. (Runs, in order, with times.)
If the parcel is late, you look for the stop that took the longest. (Find the slowest run.)
If it arrived broken, you look at what happened at each stop. (Open a run and read its inputs and outputs.)
Comparing two parcels on the same route shows whether the delay was normal or a one-off. (Compare traces.)

The tree, line by line

This is the trace of our umbrella question, printed from the runs the agent sent. Read it like this:

LangGraph is the root: the whole graph.invoke(). 10.80 s in total.
agent and tools are the graph’s nodes, in the order they ran: agent, tools, agent, tools, agent.
Inside each agent: RunnableSequence (our prompt | model | parser), with ChatOllama (the model call, run_type llm) and PydanticOutputParser (turning the text into a Step).
should_continue is the router from Lesson 3.4 - it shows up as its own tiny run after each agent step.
In the LangSmith app this is the tree on the left; clicking a line shows its details on the right.

show_trace.py - print a trace as a tree

"""Print a trace the way LangSmith shows it: a tree of runs with type, time and tokens."""
from datetime import datetime
from read_runs import load_runs          # turns the uploads saved in Lesson 5.2 back into runs


def seconds(run):
    start = datetime.fromisoformat(run["start_time"].replace("Z", "+00:00"))
    end = datetime.fromisoformat(run["end_time"].replace("Z", "+00:00"))
    return (end - start).total_seconds()


def tokens(run):
    for gen in (run.get("outputs") or {}).get("generations", [[]])[0] if run["run_type"] == "llm" else []:
        usage = gen.get("message", {}).get("kwargs", {}).get("usage_metadata")
        if usage:
            return f'  tokens {usage["input_tokens"]} in / {usage["output_tokens"]} out'
    return ""


runs = load_runs()
children = {}
for run in runs.values():
    children.setdefault(run.get("parent_run_id"), []).append(run)

def show(run, depth=0):
    print(f'{"   " * depth}{run["name"]:<{34 - 3 * depth}} {run["run_type"]:<8} {seconds(run):5.2f} s{tokens(run)}'
          + ("  ERROR" if run.get("error") else ""))
    for child in sorted(children.get(run["id"], []), key=lambda r: r["dotted_order"]):
        show(child, depth + 1)

for root in children[None]:
    print("project:", root.get("session_name"), "| trace:", root["trace_id"][:8], "| tags:", root.get("tags"))
    show(root)

Output - the first trace (model not loaded yet)

project: helpdesk-agent | trace: 01a12eb8 | tags: []
LangGraph                          chain    10.80 s
   agent                           chain     6.07 s
      RunnableSequence             chain     6.07 s
         ChatOllama                llm       6.06 s  tokens 91 in / 16 out
         PydanticOutputParser      parser    0.00 s
      should_continue              chain     0.00 s
   tools                           chain     0.00 s
   agent                           chain     1.02 s
      RunnableSequence             chain     1.02 s
         ChatOllama                llm       1.02 s  tokens 108 in / 17 out
         PydanticOutputParser      parser    0.00 s
      should_continue              chain     0.00 s
   tools                           chain     0.00 s
   agent                           chain     3.68 s
      RunnableSequence             chain     3.67 s
         ChatOllama                llm       3.67 s  tokens 123 in / 69 out
         PydanticOutputParser      parser    0.00 s
      should_continue              chain     0.00 s

Question 1 - where did the time go?

Look down the time column. Almost all of the 10.80 s is in the three ChatOllama runs:

Tools, parsers and the router took 0.00 s. Our code is not the problem - the model is.
Call 1: 6.06 s for 16 output tokens. Call 2: 1.02 s for 17. Almost the same work, six times the time.
That is a cold start: llama3 was not in memory, so the first call loaded it (Lesson 5.6).
Call 3: 3.67 s for 69 output tokens - writing the long final answer. Writing is the slow part.
So the two ways to make this faster: keep the model loaded, and make the final answer shorter.

Question 2 - where did the tokens go?

Tokens in grew with every call: 91 -> 108 -> 123. Each agent step sends the whole history again (Lesson 5.6). Long loops get more expensive with every round.
Tokens out were small for decisions (16, 17) and large for the answer (69).
In the LangSmith app, token counts appear on each llm run and are added up for the whole trace. With a paid model, cost = tokens x price.

Question 3 - what exactly did the model see?

When an answer is wrong, open the llm run. It shows the exact messages the model received and the exact text it returned. Here is the second model call:

metadata says which node and step it belongs to (langgraph_node "agent", step 3), and which model, provider and temperature were used.
inputs are the real messages: our system prompt, then the question with the history so far - the weather observation is already there.
The output text is the model’s raw JSON. The parser run after it turns it into a Step.
This is where you find most agent bugs: a missing observation, a confusing prompt, or a model answer the parser misread (Lesson 5.1).

inspect_llm.py - the details of one model run

import json
from read_runs import load_runs
runs = sorted(load_runs().values(), key=lambda r: r["dotted_order"])
llm = [r for r in runs if r["run_type"] == "llm"][1]                 # the second model call
print("name:", llm["name"], "| run_type:", llm["run_type"])
meta = llm["extra"]["metadata"]
print("metadata:", {k: meta[k] for k in sorted(meta) if k.startswith("ls_") or k in ("langgraph_node", "langgraph_step")})
print("--- inputs (the messages the model saw):")
for m in llm["inputs"]["messages"][0]:
    print(f'  [{m["kwargs"]["type"]}]', m["kwargs"]["content"])
gen = llm["outputs"]["generations"][0][0]
print("--- output text:", gen["text"])
print("--- usage:", gen["message"]["kwargs"]["usage_metadata"])
tools = [r for r in runs if r["name"] == "tools"][0]
print("--- first tools run, outputs:", tools["outputs"]["history"])

Output

name: ChatOllama | run_type: llm
metadata: {'langgraph_node': 'agent', 'langgraph_step': 3, 'ls_integration': 'langchain_chat_model', 'ls_model_name': 'llama3', 'ls_model_type': 'chat', 'ls_provider': 'ollama', 'ls_temperature': 0.0}
--- inputs (the messages the model saw):
  [system] You answer questions using two tools: get_weather(city) and calculate(expression). Choose ONE next action. Use a tool for each piece of information you do not have yet. Never repeat an action that already has an Observation. When the Observations contain everything needed, reply with final_answer.
  [human] Question: Should I bring an umbrella in Mumbai, and what is 12 * 8?
Action: get_weather('Mumbai')
Observation: Rainy, 27°C
--- output text: {"action": "calculate", "action_input": "12 * 8"}
--- usage: {'input_tokens': 108, 'output_tokens': 17, 'total_tokens': 125}
--- first tools run, outputs: ["Action: get_weather('Mumbai')", 'Observation: Rainy, 27°C']

Question 4 - is it always like this? Compare two traces

One trace is one example. We ran the same question again, later, with the model still loaded:

Total: 10.80 s the first time, 5.73 s the second.
The first model call: 6.06 s -> 1.02 s. The model was already loaded.
Everything else was almost the same: the same tree, the same tokens (91/16, 108/17, 123/69), the last call 3.67 s -> 3.66 s.
So the slow first trace was a cold start, not a problem in the agent. Without comparing, you might have "fixed" the wrong thing (Lesson 5.1: optimising the wrong step).

Output - the second trace (model already loaded)

project: helpdesk-agent | trace: 01a12eba | tags: []
LangGraph                          chain     5.73 s
   agent                           chain     1.03 s
      RunnableSequence             chain     1.03 s
         ChatOllama                llm       1.02 s  tokens 91 in / 16 out
         PydanticOutputParser      parser    0.00 s
      should_continue              chain     0.00 s
   tools                           chain     0.00 s
   agent                           chain     1.01 s
      RunnableSequence             chain     1.01 s
         ChatOllama                llm       1.01 s  tokens 108 in / 17 out
         PydanticOutputParser      parser    0.00 s
      should_continue              chain     0.00 s
   tools                           chain     0.00 s
   agent                           chain     3.66 s
      RunnableSequence             chain     3.66 s
         ChatOllama                llm       3.66 s  tokens 123 in / 69 out
         PydanticOutputParser      parser    0.00 s
      should_continue              chain     0.00 s

Question 5 - did anything fail?

Errors are marked on the run where they happened, and on the runs above it:

In Lesson 5.2 the calculate tool raised ZeroDivisionError. Its run was sent with an error field holding the exception and the traceback - in the app it is shown in red.
But an error returned as TEXT is not an error to LangSmith. Our helpdesk calculate() returns "Error: only + - * / ..." as a normal result - the run looks successful.
So read the outputs too, not only the red marks. Or raise real exceptions where you want failures to be visible.

In the LangSmith app

With your real key (Lesson 5.2), open your project. You will find:

A list of traces, newest first, with their latency, token count and status.
Clicking a trace opens the tree (left) and the selected run’s details (right): inputs, outputs, metadata, timings, tokens, errors.
Filters: by tag, by metadata (user_id = u-42), by status, by latency - useful when you have thousands of traces.
The same five questions work there: what happened, where did the time go, where did the tokens go, what did the model see, did anything fail.

Tip: Before changing an agent, save the link to a typical trace. After the change, compare the new trace with it. A trace before and after is the simplest proof that a change helped.

The recipe: five questions for every trace

1. What happened? Read the tree top-down: which nodes ran, in what order.
2. Where did the time go? Find the biggest latency - usually an llm run.
3. Where did the tokens go? Look at tokens in (history growing?) and out (long answers?).
4. What did the model see? Open the llm run: exact messages and exact output.
5. Did anything fail? Check errors - and outputs that contain error text.
Then compare with another trace of the same question before you change anything.

Reading a trace at a glance

Root run

The whole request.

LangGraph  chain  10.80 s

Node run

One graph step.

agent / tools  chain

Model call

Time and tokens.

ChatOllama  llm  6.06 s  91 in / 16 out

Parser

Text -> structured.

PydanticOutputParser  parser

Router

Which way next.

should_continue  chain  0.00 s

Model metadata

On every llm run.

ls_model_name, ls_provider, ls_temperature

Try it yourself

The code does not change. Swap the content string and the program does something else entirely.

Your own trace

“Trace a question that needs only the calculator. How many agent steps do you expect, and how many do you see?”

Cold vs warm

“Stop Ollama (or wait until it unloads the model) and trace the same question twice. Compare the first ChatOllama run.”

Find the history

“Open the third llm run. How many Observation lines did the model see?”

Make an error visible

“Change calculate() to raise an exception instead of returning "Error: ...". How does the trace change?”

What usually goes wrong

Judging from one trace

Our first trace was 10.80 s because of a cold start; the next was 5.73 s. Compare before you fix.

Looking only at the total time

The total hides the cause. The tree showed 0.00 s for tools and almost everything in model calls.

Only looking for red errors

Errors returned as text look like success. Read the outputs too.

Key points

A trace is a tree: the root is the whole run, children are the steps, in order.
run_type tells you what each step is: chain, llm, tool, parser.
In our trace almost all time was in model calls; the first call was slow because the model was loading.
Tokens in grow every round (91 -> 108 -> 123) because the history is sent again.
An llm run shows the exact messages the model saw and its exact output - where most bugs are found.
Compare two traces before changing anything: cold 10.80 s vs warm 5.73 s.

Quick check before you move on

Which runs took almost all of the time?

The ChatOllama (llm) runs. Tools, parsers and the router took 0.00 s.

Why was the first model call 6.06 s and the second 1.02 s?

The first call had to load llama3 into memory (a cold start).

Why do tokens in grow with each call?

Each agent step sends the whole history again, and the history grows.

Where do you see exactly what the model was given?

In the inputs of the llm run.

Quiz

1.
The last model call wrote 69 tokens and took 3.67 s. What does that tell you?
2.
What is should_continue in the tree?
3.
A tool returns "Error: ..." as text. How does it look in the trace?
4.
Why compare two traces of the same question?

Interview questions

How do you debug a slow LLM agent?

Open its trace, find the runs with the largest latency (usually model calls), check tokens in/out per call, look for cold starts, repeated calls and growing context, and compare against other traces before optimising.

What information does a trace give you that logs do not?

The causal tree of steps with timings, the exact model inputs and outputs, token usage, and errors in context - for one specific request.

Comments

Loading comments...