Skip to content

fix(debug): record native tool span startTimeUnixNano before execution#1809

Merged
bug-ops merged 1 commit intomainfrom
native-tool-span-start-time
Mar 15, 2026
Merged

fix(debug): record native tool span startTimeUnixNano before execution#1809
bug-ops merged 1 commit intomainfrom
native-tool-span-start-time

Conversation

@bug-ops
Copy link
Owner

@bug-ops bug-ops commented Mar 15, 2026

Summary

  • begin_tool_call in the post-hoc assembly path (handle_native_tool_calls) was called after tool execution, causing startTimeUnixNano to reflect the post-execution wall clock instead of the dispatch time
  • Duration/latency were correct, but the span's position on the Jaeger/Grafana timeline was shifted by the full tool execution time
  • Added TracingCollector::begin_tool_call_at(&Instant) that back-computes Unix nanos via now_unix_nanos().saturating_sub(elapsed_nanos) — clean, no clock-type change
  • native.rs now passes the existing started_at instant; legacy.rs and tests unchanged
  • Added begin_tool_call_at_timestamps_precede_end_time unit test

Test plan

  • cargo nextest run --workspace --features full --lib --bins — 5788 passed
  • cargo clippy --workspace --features full -- -D warnings — clean
  • cargo +nightly fmt --check — clean

Closes #1798.

In the post-hoc assembly path (handle_native_tool_calls), begin_tool_call
was called after tool execution, so startTimeUnixNano reflected the
post-execution wall clock rather than when the tool was dispatched.
Latency was correct but the span was shifted on the Jaeger/Grafana timeline.

Add TracingCollector::begin_tool_call_at accepting a pre-recorded Instant
and computing Unix nanos via now_unix_nanos().saturating_sub(elapsed).
Existing begin_tool_call delegates to it with Instant::now() (legacy.rs
path unaffected). native.rs now passes the existing started_at Instant.

Add begin_tool_call_at_timestamps_precede_end_time unit test.

Closes #1798.
@github-actions github-actions bot added documentation Improvements or additions to documentation rust Rust code changes core zeph-core crate labels Mar 15, 2026
@bug-ops bug-ops enabled auto-merge (squash) March 15, 2026 02:59
@github-actions github-actions bot added bug Something isn't working size/M Medium PR (51-200 lines) labels Mar 15, 2026
@bug-ops bug-ops merged commit 371ae2d into main Mar 15, 2026
15 checks passed
@bug-ops bug-ops deleted the native-tool-span-start-time branch March 15, 2026 03:07
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working core zeph-core crate documentation Improvements or additions to documentation rust Rust code changes size/M Medium PR (51-200 lines)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

fix(debug): native tool span startTimeUnixNano records post-execution time

1 participant