DEV Community

Sarthak Rawat
Sarthak Rawat

Posted on

My AI Support Bot Was Slow. Then SigNoz Told Me My Alert Would Fire in 158 Years.

Author's Note

This project was built as part of the Agents of SigNoz hackathon organized by WeMakeDevs and SigNoz.

Source code: https://github.com/SarthakRawat-1/signoz-assistant

How I traced a real latency problem, a real auth failure, and one genuinely baffling unit-conversion bug in an AI support assistant, using OpenTelemetry and self-hosted SigNoz.

I built a small AI support assistant for an imaginary ecommerce company, the kind that answers "where's my order" and "will the rain delay my delivery." It worked, then I sent it 25 requests back to back and some took over three seconds. No errors, no crashes, just slow, some of the time. I had no idea which part, so I did what I should have done from the start: instrumented it and watched.

Two things came out of that afternoon. One was a real, boring, entirely explainable latency bug. The other was SigNoz telling me an alert would trigger in roughly 158 years, which is not a sentence I expected to type while debugging a chatbot.

What I built

Architecture diagram: Client/Seed Script → FastAPI App → SQLite DB, Gemini API, Open-Meteo API, and SigNoz OTel Collector

The app is small on purpose: a FastAPI endpoint (POST /support/chat) that takes a message and a conversation_id, stores history in SQLite, optionally calls a weather API if the message looks shipping-related, and generates a reply. A small frontend on top shows the trace ID and classified intent for whatever you just sent, mostly so I didn't have to keep tabbing over to SigNoz to find which trace belonged to which message.

The chat interface, with a live panel showing the trace ID and classified intent for the last message

One honest disclosure: I didn't have a Gemini API key wired in for most of this session, so the LLM calls below are running against a stub client, not live Gemini. My code logs this plainly: No GEMINI_API_KEY set. Falling back to Stub LLM Client. It doesn't affect the story, since the point was never to benchmark Gemini, it was to see whether SigNoz would correctly point at the real bottleneck regardless of which piece was mocked. It did.

The weather lookup is where the interesting instrumentation lives, a manual span wrapping both outbound calls with business-relevant attributes attached along the way:

async def get_weather(city: str) -> dict:
    with tracer.start_as_current_span("weather.lookup_operation") as span:
        span.set_attribute("weather.city", city)

        async with httpx.AsyncClient() as client:
            geo_response = await client.get(GEOCODING_URL, params={"name": city, "count": 1})
            span.set_attribute("weather.geocoding.http.status_code", geo_response.status_code)

            lat, lon = _extract_coords(geo_response.json())
            span.set_attributes({"weather.latitude": lat, "weather.longitude": lon})

            forecast_response = await client.get(FORECAST_URL, params={"latitude": lat, "longitude": lon})
            span.set_attribute("weather.forecast.http.status_code", forecast_response.status_code)
            # ...response is parsed into a simplified condition below, trimmed here
Enter fullscreen mode Exit fullscreen mode

The two client.get() calls, one geocoding, one forecast, are the two GET spans stacked under weather.lookup_operation in the waterfall below. Attaching customer.intent and conversation.id to spans like this let me filter traces by business behavior, "show me every shipping_delay conversation," instead of only by HTTP endpoint, which mattered more once several conversations were running at once.

No agent framework, no tool-calling loop, no vector database. Just enough moving parts to produce interesting telemetry.

Getting visibility

I self-hosted SigNoz using Foundry, their newer install method that replaced the old docker-compose-based install a few months back: install the CLI, point it at a small YAML file, and it stands up ClickHouse, the OTel collector, and the UI itself. I added HTTPXClientInstrumentor on top of FastAPI's auto-instrumentation, plus manual spans around the LLM call and the weather lookup.

None of it went smoothly first try. Docker Desktop was running, but its CLI binaries weren't on my shell's PATH, so foundryctl cast failed outright with tools are not available, please install them and try again: docker, docker-compose, a two-minute fix once I found it. Then logs didn't show up in SigNoz at all, because auto-instrumented logging assumes your app and collector share stdout, which isn't true when your app runs on the host and SigNoz runs in Docker. Configuring an OTLP log exporter to ship logs over gRPC fixed it, and correlation with traces worked immediately after.

Investigation #1: the actual slow part

Trace waterfall showing weather.lookup_operation taking 3.06s against a 405ms LLM call

Once data was flowing, I sorted traces by duration and opened the slowest one. Without the waterfall view, I'd probably have blamed Gemini first, since it's the component that looks expensive on paper. The trace showed I was about to optimize the wrong thing entirely: weather.lookup_operation took 3.06 seconds. The instrumented LLM span, right next to it, took 405 milliseconds. This wasn't a fluke. I checked several of the slow traces, and the same pattern held every time.

I built a small dashboard to track this at the aggregate level too: p95 latency on the endpoint, error rate, and average LLM token count.

Custom dashboard with three panels: P95 Latency for POST /support/chat, Request Error Rate, and Avg LLM Token Count

Across 25 seeded requests, the endpoint's overall p50 was a perfectly reasonable 484ms, but p99 jumped to 3.37 seconds. weather.lookup_operation alone had a p50 of 2.4 seconds. Four requests triggered it; all four were the slow ones.

Neither call is artificially delayed; there's no sleep() anywhere in that path. Two things make it slow: the calls are sequential, since you need coordinates before requesting a forecast, and each request creates a new AsyncClient instead of reusing one, so every lookup pays the cost of a fresh connection twice. Mundane, fixable, and something I'd never have found by reading logs alone; the waterfall made both GET calls and their relative cost obvious at a glance.

Investigation #2: an intentional failure

The second investigation, unlike the first, was deliberate. I temporarily set an invalid Gemini API key to see what a real auth failure would look like end to end.

Log entry showing

The result showed up as an ERROR-level log, Request failed with exception, with a trace_id attached directly to the log line. Clicking that ID took me straight to the exact trace where the failure happened, no manual correlation required. This is the kind of thing that's genuinely hard to appreciate until you've done the alternative: grepping through unstructured logs trying to match timestamps to a request you think might be related.

The bug I didn't expect: nanoseconds pretending to be years

This is the one I'd actually lead with if I were telling this story out loud. I set up an alert: notify me if p95 latency on /support/chat goes above 4 seconds. Simple enough. Except when I opened the alert's chart to sanity-check it, the y-axis read 158.44 years, with the critical threshold drawn at 126.76 years.

Alert chart with a y-axis labeled in years: 158.44 years at the top, a critical threshold line at 126.76 years

SigNoz's alert query builder operates on duration_nano, nanoseconds, not milliseconds. I'd set my threshold to 4000, assuming milliseconds. It meant 4000 nanoseconds, roughly the time it takes an electron to get mildly annoyed, so every request blew past it instantly, and the chart rescaled itself into whatever unit made the numbers legible: years. The fix was 4000000000 (4 billion nanoseconds, i.e., 4 seconds). The lesson wasn't "SigNoz is confusing," it was that observability tools expose raw units because precision matters at the storage layer, and it's on you to know exactly what you're alerting on.

With the units corrected, the same alert did exactly what I'd originally wanted. It stayed quiet during normal traffic and fired only once a request genuinely crossed 4 seconds.

Alert Rules page showing

I couldn't find this mentioned anywhere in the getting-started docs, and it took me longer than I'd like to admit to realize the alert itself was working correctly and my units weren't.

What actually changed for me

Before this, I thought of observability mostly as dashboards: numbers on a screen telling you something's wrong. What I didn't expect is how much of the actual debugging happens in traces, not metrics. A metric can tell you p99 latency is bad; it can't tell you why. The trace waterfall explained the "why," span by span, in a way I could act on immediately instead of forming a hypothesis and checking it against logs one line at a time.

The other shift is smaller but sticks with me: I used to think of alerts as something you configure once you already understand your system. This one taught me the alert itself needs debugging too, not just the app it's watching.

One thing I appreciated only after the fact: none of this instrumentation is actually SigNoz-specific. The spans and attributes are emitted through OpenTelemetry, a vendor-neutral standard; SigNoz just happens to be the backend consuming them here. That's why it felt like a real part of the application rather than something bolted on for one dashboard.

Conclusion

Before this, "my app is slow" would have meant staring at logs and guessing. After wiring up OpenTelemetry and SigNoz, every request told its own story: which span cost what, which log line belonged to which trace, and, once, which threshold was off by a factor of a million. Next, I'd share one long-lived httpx.AsyncClient instead of opening a new one per request, run the geocoding and forecast calls concurrently, and wire in a real Gemini key just to see what surprises a live model call brings. I didn't get a dramatic engineering war story out of this. I got a small, boring, entirely real latency bug, an honest auth failure, and one legitimately funny unit-conversion mistake. That's a fair trade for an afternoon.

Top comments (1)

Collapse
 
raju_dandigam profile image
Raju Dandigam

Showing the trace ID in the UI is a small detail, but it makes the rest of the debugging loop practical. The post lands the right point that “slow sometimes” is usually a cross-service trace problem, not an app-log problem, and the 158-year alert is exactly the kind of unit mismatch that only becomes obvious once telemetry is wired end to end.

I also like that you separated real latency, auth failure, and alert math instead of calling all three “observability.” Those are different failure classes, and they need different fixes even when they all show up during the same debugging session. That is also why tools like agent-inspect matter for agent workflows: you need a human-debuggable execution path, not just a pile of events.

Curious whether you found one span or attribute that became the minimum viable clue for most support incidents.