What I built
The agent is small on purpose. You give it a topic, and it does three things: it asks an LLM to break the topic into three sub-questions, answers each of those questions with a separate LLM call, then makes one final call to combine the answers into a short summary. It's built with FastAPI and uses OpenAI's gpt-4o-mini.
That's five LLM calls for a single request. It always returned a sensible answer, so functionally it was "done." But a normal HTTP log only tells me the whole request took ten seconds, not which of those five calls ate the time, how many tokens each one burned, or whether any of them could have run at the same time. That's the gap I wanted to close, and it's exactly what tracing is for: seeing inside one request, step by step.
Setting up SigNoz on Windows (WSL 2)
What you'll need to follow along: Windows with WSL 2 (I used Ubuntu), Docker, Python 3, and an OpenAI API key.
I self-hosted SigNoz rather than using a cloud version, because I wanted the whole stack on my own machine. On Windows that means working inside WSL 2, and the first thing I learned is that the Docker you think you have isn't always the Docker you can use.
I had Docker Desktop installed, but running docker inside my Ubuntu WSL distro gave me this:
The command 'docker' could not be found in this WSL 2 distro.
Docker Desktop keeps its engine in its own separate WSL distro, and mine wasn't wired into Ubuntu. Rather than fight the Docker Desktop integration, I installed Docker natively inside Ubuntu instead:
curl -fsSL https://get.docker.com | sh
sudo usermod -aG docker $USER
After a wsl --shutdown and reopening Ubuntu, docker ps finally returned a clean, empty table. That was the sign the daemon was actually reachable.
Then SigNoz itself, using their Foundry CLI (the current install method; the older install.sh script is deprecated):
curl -fsSL https://signoz.io/foundry.sh | bash
I created a casting.yaml describing the install, ran foundryctl cast -f casting.yaml, and after a few minutes of image pulls, docker ps showed the full stack healthy: SigNoz on port 8080, the OTel collector on 4317/4318. One quirk: the signoz-mcp container shows as unhealthy, but that's a cosmetic healthcheck issue, not a real failure.
Here's how the whole thing fits together:
POST /research
│
▼
┌──────────────────┐
│ FastAPI agent │ plan → answer ×3 → combine (5 LLM calls)
│ (WSL 2 host) │
└────────┬─────────┘
│ OpenTelemetry SDK
│ OTLP → localhost:4318
▼
┌──────────────────────────┐
│ SigNoz OTel Collector │ (Docker, port 4317/4318)
└────────┬─────────────────┘
▼
┌──────────────┐ ┌──────────────────┐
│ ClickHouse │◄─────│ SigNoz UI │ traces · metrics
│ (storage) │ │ :8080 │ dashboards · alerts
└──────────────┘ └──────────────────┘
Testing the pipe before trusting it
Before I instrumented my real app, I wanted to know the telemetry pipeline actually worked. So I fired a handful of test traces straight at the collector with telemetrygen, over the Docker network:
docker run --rm --network signoz-network \
ghcr.io/open-telemetry/opentelemetry-collector-contrib/telemetrygen:latest \
traces --otlp-endpoint signoz-ingester-1:4317 --otlp-insecure --traces 5
Within about thirty seconds, a telemetrygen service showed up in SigNoz with five traces. That confirmed the whole path was working: collector to ClickHouse to the UI. It paid off later. When my own app's data was slow to appear, I already knew the pipeline was fine and the problem was my config.
[SCREENSHOT: telemetrygen traces in SigNoz (optional)]
Instrumenting the agent
With SigNoz running, I needed the agent to actually send it data. OpenTelemetry has two levels of this, and I used both.
First, auto-instrumentation, the low-effort win. A couple of installs and a wrapper command, no code changes:
pip install opentelemetry-distro opentelemetry-exporter-otlp opentelemetry-instrumentation-fastapi
opentelemetry-bootstrap -a install
Then I ran the app through the OpenTelemetry wrapper instead of plain uvicorn:
opentelemetry-instrument uvicorn app:app --port 8001
One detail that trips people up: my app runs on the WSL host, not inside Docker, so the telemetry endpoint is localhost:4318, not the container name signoz-ingester-1 you'd use from inside the Docker network. Getting that wrong is a silent failure: data just never shows up, with no error.
That alone got the incoming FastAPI request and the OpenAI calls into SigNoz. But auto-instrumentation gives you generic spans, "chat gpt-4o-mini" five times. It can't tell you which step of my pipeline each call belongs to. So I added manual spans to label the stages and attach the numbers I actually cared about:
def ask_llm(step_name: str, prompt: str) -> str:
with tracer.start_as_current_span(step_name) as span:
resp = client.chat.completions.create(
model=MODEL,
messages=[{"role": "user", "content": prompt}],
)
u = resp.usage
span.set_attribute("llm.total_tokens", u.total_tokens)
span.set_attribute("llm.cost_usd", u.prompt_tokens * PRICE_IN + u.completion_tokens * PRICE_OUT)
return resp.choices[0].message.content
Now every LLM span carries its real token count and dollar cost, and the pipeline stages (plan_questions, answer_questions, combine_summary) show up as named spans in the trace instead of anonymous HTTP calls. (In my runs, a single research request cost about $[FILL IN from your llm.cost_usd spans] in tokens.)
Looking inside: the staircase
Once the custom spans were flowing, I opened one /research trace in SigNoz and finally saw where those ten seconds went. The flame graph made it obvious in a way no log ever could.
The five LLM calls weren't overlapping. They were running one after another, in a perfect staircase. plan_questions finished, then the first answer call started, then the second, then the third, then the combine step. Each step waited for the one before it.
The numbers told the story:
- Total request: 10.48s
-
answer_questionsalone: 6.54s, more than half the entire request - Inside it, three separate answer calls running back to back (roughly 2.76s, 1.33s, and 2.45s)
And here's the thing that made it click: those three answer calls are completely independent. Answering one sub-question doesn't depend on the answer to another. They were only running one at a time because I'd written a plain for loop. That's the most natural way to write it, and the most wasteful. My agent was making the LLM wait in line for no reason.
I hadn't planned this bug. I didn't even know it was there until the trace drew it for me. That's the part that sold me on tracing: the inefficiency wasn't in my code review or my logs. It was sitting in the shape of the waterfall, plain as day.
The fix: stop waiting in line
The fix followed directly from what the trace showed. If the three answer calls are independent, they shouldn't run one at a time. They should run at once. I swapped the sequential for loop for a thread pool so all three fire in parallel:
with ThreadPoolExecutor(max_workers=3) as pool:
futures = [
pool.submit(ask_llm_ctx, ctx, f"llm.answer_{i+1}", f"Answer in 2 sentences: {question}")
for i, question in enumerate(questions)
]
answers = [f.result() for f in futures]
But this is where I hit a real gotcha, and it's one worth knowing if you trace anything threaded: OpenTelemetry's trace context doesn't automatically cross into new threads. The first time I ran the parallel version, the three answer spans detached and floated off as their own separate traces instead of nesting under the request, and the waterfall fell apart.
The fix was to capture the current context before spawning the threads and re-attach it inside each worker:
def ask_llm_ctx(ctx, step_name, prompt):
token = attach(ctx)
try:
return ask_llm(step_name, prompt)
finally:
detach(token)
With that in place, I re-ran the same request and opened the new trace. The staircase was gone. The three answer calls now started together and overlapped. answer_questions collapsed from 6.54s down to about 1.65s, roughly the length of its single slowest call instead of the sum of all three.
The whole request dropped from 10.48s to 5.62s, about a 46% cut, from a change that only worked because a trace showed me where to make it.
Here's the full endpoint after the fix, so you can reproduce it (the only real change from the original is that step 2 runs in a thread pool instead of a plain for loop):
from concurrent.futures import ThreadPoolExecutor
from opentelemetry import trace
from opentelemetry.context import attach, detach, get_current
tracer = trace.get_tracer("ai-research-agent")
@app.post("/research")
def research(q: Query):
with tracer.start_as_current_span("research_pipeline") as root:
root.set_attribute("research.topic", q.topic)
# 1. plan: break the topic into 3 sub-questions
with tracer.start_as_current_span("plan_questions"):
plan = ask_llm("llm.plan",
f"Give 3 short sub-questions about: {q.topic}. One per line, no numbering.")
questions = [l.strip() for l in plan.splitlines() if l.strip()][:3]
# 2. answer: independent calls, run in parallel (the fix)
with tracer.start_as_current_span("answer_questions"):
ctx = get_current()
with ThreadPoolExecutor(max_workers=3) as pool:
futures = [
pool.submit(ask_llm_ctx, ctx, f"llm.answer_{i+1}",
f"Answer in 2 sentences: {question}")
for i, question in enumerate(questions)
]
answers = [f.result() for f in futures]
# 3. combine into a summary
with tracer.start_as_current_span("combine_summary"):
summary = ask_llm("llm.combine",
"Combine these into a short paragraph:\n" + "\n".join(answers))
return {"topic": q.topic, "questions": questions, "summary": summary}
Beyond a single trace: a dashboard and an alert
One trace showed me the problem, but a trace is a single request. To watch behavior over time, I built a dashboard panel plotting the p95 latency of POST /research from my trace data (p95(durationNano), filtered to the service).
Because I'd run the slow sequential version and the fast parallel version, the panel captured the whole story in one line: latency sitting up around 10 seconds, then dropping and settling near 5 after the fix. The optimization I'd just made, visible as a trend instead of a one-off.
Then I added a guardrail: a trace-based alert that fires if p95 latency goes above 8 seconds at least once in a 5-minute window. The idea is simple: if the sequential slowdown ever creeps back in (a bad refactor, a new blocking call), I want to know before a user does. I wired it to a test webhook and fired a test notification to confirm it actually delivers.
One small thing worth flagging for anyone following along: SigNoz won't let you save an alert rule without attaching a notification channel, so create the channel first, then the rule.
What I'd tell myself before starting
A few things I actually took away from this:
Auto-instrumentation shows you the shape; custom spans give you the answers. The wrapper got data flowing in minutes, but it was generic: five anonymous LLM calls. The insight only appeared once I added my own named spans and attached token and cost numbers. The low-effort version is worth doing first, but it's not where the value is.
A trace can show you things a code review won't. I'd read that for loop plenty of times and never thought twice about it. It took seeing the staircase in the flame graph to realize those calls were independent and could run in parallel. The bug wasn't hidden in the code. It was hidden in the timing, and timing is exactly what a trace makes visible.
On Windows, install Docker inside WSL, not around it. Fighting Docker Desktop's WSL integration wasn't worth it. A native install inside Ubuntu was simpler and just worked.
Prove your telemetry pipeline before you build on it. Before instrumenting anything real, I sent a handful of test traces with telemetrygen and confirmed they landed in SigNoz. That five-minute check meant that when my app's data didn't show up later, I knew the pipeline was fine and the problem was my config, not the other way around.
Wrapping up
I started the night unable to run docker in my terminal and ended it watching a trace tell me exactly why my AI agent was twice as slow as it needed to be, then watching that same tool confirm the fix worked. The agent's output never changed; what changed is that I could finally see what it was doing. That's the whole point: you can't fix what you can't see, and for a multi-step AI agent, a trace is how you see it.
If you want to try the same thing, everything I used is open source and self-hostable: SigNoz, OpenTelemetry, and the OpenAI Python SDK. Self-host SigNoz, instrument one real app you already have, and open a single trace. I'd bet you find something you didn't expect, too.
Top comments (0)