DEV Community

Nikhilesh
Nikhilesh

Posted on

I Found a Timing Gap in AI Agent Tool-Calling — Here's How I Traced It With SigNoz

I wasn't initially looking for a timing bug. I was reading through the competition SDK, tracing how the evaluation environment interacted with the agent after every env.interact() call, when I noticed that safety validation and tool execution weren't always obviously synchronized. That made me wonder whether there could be a small execution window where a tool finished running before its validation result was even available — so I built a minimal reproduction to check.

Why this matters

AI agents are increasingly given real permissions — reading files, running commands, calling APIs. The standard safety pattern is check, then act: validate that an input is safe (a "taint check"), and only then let the agent execute the action.

The assumption baked into that pattern is that the check finishes before the action starts. While competing in a Kaggle AI agent security challenge, I was tracing how the evaluation SDK sequenced validation and tool execution around each env.interact() call. I found that some agent implementations don't actually enforce that ordering — the tool call can fire while the safety check is still in flight. If the input turns out to be unsafe, by the time you find out, the damage is already done.

I wanted to see this happen in an actual trace, not just reason about it on paper — so I built a minimal reproduction and instrumented it with OpenTelemetry, running it against a self-hosted SigNoz instance.

Reproducing it

I wrote a small Python script with two versions of the same agent step:

The vulnerable version kicks off the taint check as a background task, but doesn't wait for it before running the tool:

async def vulnerable_agent_step(user_input: str):
    with tracer.start_as_current_span("agent_step_vulnerable"):
        check_task = asyncio.create_task(taint_check(user_input))
        result = await tool_call(user_input)   # runs immediately
        is_safe = await check_task             # resolves too late
        return result, is_safe
Enter fullscreen mode Exit fullscreen mode

The fixed version waits for the check to resolve first:

async def fixed_agent_step(user_input: str):
    with tracer.start_as_current_span("agent_step_fixed"):
        is_safe = await taint_check(user_input)
        if not is_safe:
            return "BLOCKED: failed taint check", is_safe
        result = await tool_call(user_input)
        return result, is_safe
Enter fullscreen mode Exit fullscreen mode

Both taint_check and tool_call are wrapped in OpenTelemetry spans, exported to a self-hosted SigNoz instance running locally via Docker.

I ran both versions against a deliberately unsafe payload (a path traversal + destructive shell command). The console output alone already told the story:

--- Running VULNERABLE pattern ---
result='executed: ../../etc/passwd; rm -rf /' is_safe=False (tool already ran regardless)

--- Running FIXED pattern ---
result='BLOCKED: failed taint check' is_safe=False
Enter fullscreen mode Exit fullscreen mode

The unsafe input was flagged correctly in both cases — but in the vulnerable version, the tool had already executed by the time that answer came back.

What the trace actually shows

SigNoz trace showing the tool_call span overlapping with the taint_check span in the vulnerable agent pattern
This is where SigNoz made the bug undeniable instead of theoretical. In the vulnerable trace, taint_check runs for 301.18ms — but tool_call starts at the same timestamp and finishes in 51.09ms, well before the check resolves. The whole agent_step_vulnerable span is 301.37ms, and for roughly 250ms of that window, the tool has already run while validation is still pending.
SigNoz trace showing the fixed agent pattern with sequential, non-overlapping spans
The fixed trace tells a completely different story — and not just in timing. It only has two spans, not three. tool_call doesn't appear in the trace at all, because taint_check (300.77ms) blocked it before it ever ran. The vulnerable trace has three spans because the tool executes regardless of the outcome; the fixed trace has two because a failed check means the tool call never happens.

That's the clearest signal a trace can give you: not just "these two things overlapped," but "this step straight-up didn't happen when it should've been blocked."

What I learned

What surprised me most was how much easier this became to understand once I looked at the trace instead of the source code. Reading the async version, it looks like the safety check and tool execution are logically connected — you assume validation gates the action, because that's the order the function reads in. The waterfall trace showed otherwise immediately: the tool had already finished long before validation completed. Something that felt theoretical when I was reasoning about it from code became obvious within seconds once I could see it.

This timing gap wasn't the only pattern I found during the competition. While investigating how guardrails detected sensitive requests, I noticed that many defenses lean heavily on keyword-based matching rather than actually understanding intent. I'm treating that as a separate finding from this post — it's about input filtering, not execution ordering — but it reinforced the same broader point: a lot of agent security assumptions don't hold up once you actually go looking for the seams.

If I were starting the competition over, I'd spend far less time trying to build the most sophisticated attack immediately. I'd first understand the evaluator, the replay mechanism, the SDK, and the scoring pipeline completely, and get something simple submitted before optimizing it. Understanding the evaluation system turned out to matter just as much as generating strong attacks — and the same instinct applies here: understanding how to observe a system is often the unlock, not just knowing an issue exists.

One thing I'll say generally: this kind of bug is nearly invisible in code review. asyncio.create_task() followed by an await later in the function reads like the check happens first — you have to actually trace the execution to see that it doesn't. That's the argument for observability here: it's not just for catching performance problems, it's for catching security assumptions that the code's structure quietly violates.

Takeaways

  • Check-then-act patterns in async code are easy to get wrong in a way that's hard to spot by reading — the bug is in timing, not logic.
  • A trace turns "I think there's a race condition" into "here's the exact 250ms window where it happened."
  • Span count itself is a signal: a blocked action just... doesn't produce a span. That absence is as informative as the timing overlap.

Conclusion

Tracing didn't just confirm a suspicion — it turned a "this might be a problem" into something I could see and measure in seconds, which is exactly the difference between guessing and knowing when you're working on agent security.

If you want to reproduce this yourself: self-host SigNoz and instrument any check-then-act flow with OpenTelemetry — the gap shows up immediately once you can see it.

Top comments (0)