Add inner latency spans for agent loop executor - #5487
Conversation
|
Caution Review failedAn error occurred during the review process. Please try again later. 📝 WalkthroughWalkthroughAdds a latency-tracing helper module ( ChangesLatency instrumentation of executor pipeline
Estimated code review effort: 3 (Moderate) | ~25 minutes Sequence Diagram(s)sequenceDiagram
participant Pipeline as DefaultExecutorPipeline
participant TraceStage as trace_stage! macro
participant Latency as latency module
participant Observability as ironclaw_observability
Pipeline->>TraceStage: invoke stage (e.g. model.process, exit.process)
TraceStage->>Latency: started_at()
TraceStage->>Pipeline: await stage future
Pipeline-->>TraceStage: Result<T, E>
TraceStage->>Latency: result(operation, context, iteration, started_at, result)
alt Ok
Latency->>Observability: operation_ok trace event
else Err
Latency->>Observability: operation_error trace event
end
TraceStage-->>Pipeline: return original Result
No repo invariant docs (CLAUDE.md/AGENTS.md/.claude/rules) provided in this diff for citation. Flagging purely from the diff:
🚥 Pre-merge checks | ✅ 4✅ Passed checks (4 passed)
Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out. Comment |
There was a problem hiding this comment.
Code Review
This pull request integrates the "ironclaw_observability" crate to add latency tracing across various stages of the agent loop executor. It introduces a "trace_stage!" macro to measure and log the duration of operations. The review feedback correctly identifies three locations where the iteration number is hardcoded to "0" instead of using "state.iteration", which is necessary for accurate metrics tracking.
Important
The consumer version of Gemini Code Assist on GitHub is being sunset. Starting June 18, 2026, new organization installations will be blocked, and all code review activity will officially cease on July 17, 2026.
For more details on the timeline and next steps, please review the Help Documentation.
| state.iteration, | ||
| self.exit.process(ctx, ExitInput { state, kind }) | ||
| )?; | ||
| trace_stage!("ack_pending_input_before_exit", 0, ack.ack(host))?; |
There was a problem hiding this comment.
The iteration number is hardcoded to 0 here, but the actual iteration is available in state.iteration. Using state.iteration ensures that the latency metrics for this ACK operation are correctly associated with the specific iteration of the loop.
| trace_stage!("ack_pending_input_before_exit", 0, ack.ack(host))?; | |
| trace_stage!("ack_pending_input_before_exit", state.iteration, ack.ack(host))?; |
| state.iteration, | ||
| self.exit.process(ctx, ExitInput { state, kind }) | ||
| )?; | ||
| trace_stage!("ack_pending_input_before_exit_resume", 0, ack.ack(host))?; |
There was a problem hiding this comment.
The iteration number is hardcoded to 0 here, but the actual iteration is available in state.iteration. Using state.iteration ensures that the latency metrics for this ACK operation are correctly associated with the specific iteration of the loop.
| trace_stage!("ack_pending_input_before_exit_resume", 0, ack.ack(host))?; | |
| trace_stage!("ack_pending_input_before_exit_resume", state.iteration, ack.ack(host))?; |
| trace_stage!( | ||
| "ack_pending_input_before_exit_skip_model", | ||
| 0, | ||
| ack.ack(host) | ||
| )?; |
There was a problem hiding this comment.
The iteration number is hardcoded to 0 here, but the actual iteration is available in state.iteration. Using state.iteration ensures that the latency metrics for this ACK operation are correctly associated with the specific iteration of the loop.
| trace_stage!( | |
| "ack_pending_input_before_exit_skip_model", | |
| 0, | |
| ack.ack(host) | |
| )?; | |
| trace_stage!( | |
| "ack_pending_input_before_exit_skip_model", | |
| state.iteration, | |
| ack.ack(host) | |
| )?; |
There was a problem hiding this comment.
Actionable comments posted: 2
🤖 Prompt for all review comments with AI agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
Inline comments:
In `@crates/ironclaw_agent_loop/src/executor.rs`:
- Around line 194-201: The TurnCompletedStep::iteration helper is synthesizing a
sentinel 0 for Exit, which causes canonical.rs tracing to lose the live loop
iteration when labeling post_capability and post_capability_resume. Update
TurnCompletedStep::iteration and the callers around assistant_reply/capabilities
so Exit carries or preserves the current iteration from the caller/state instead
of returning 0, and use that value when emitting the trace boundary.
In `@crates/ironclaw_agent_loop/src/executor/canonical.rs`:
- Around line 329-334: The exit-path ack spans are being recorded with a
hardcoded iteration of 0, which makes the latency traces look like iteration-0
events instead of the active turn. Update the `trace_stage!` calls in the
`StopStep::Stop` exit path within `canonical.rs`—including the
`ack_pending_input_before_exit` variants—to use `state.iteration` (the same
iteration already available in each arm) rather than 0, so the spans are
attributed to the correct step.
🪄 Autofix (Beta)
Fix all unresolved CodeRabbit comments on this PR:
- Push a commit to this branch (recommended)
- Create a new PR with the fixes
ℹ️ Review info
⚙️ Run configuration
Configuration used: Path: .coderabbit.yaml
Review profile: ASSERTIVE
Plan: Pro Plus
Run ID: cc4bd4d9-f857-4446-895d-c8659b411ce9
⛔ Files ignored due to path filters (1)
Cargo.lockis excluded by!**/*.lock,!**/Cargo.lock
📒 Files selected for processing (4)
crates/ironclaw_agent_loop/Cargo.tomlcrates/ironclaw_agent_loop/src/executor.rscrates/ironclaw_agent_loop/src/executor/canonical.rscrates/ironclaw_agent_loop/src/executor/latency.rs
| impl TurnCompletedStep { | ||
| fn iteration(&self) -> u32 { | ||
| match self { | ||
| Self::Continue { state, .. } => state.iteration, | ||
| Self::Exit(_) => 0, | ||
| } | ||
| } | ||
| } |
There was a problem hiding this comment.
🎯 Functional Correctness | 🟡 Minor | ⚡ Quick win
Don't synthesize iteration 0 for TurnCompletedStep::Exit.
Line 198 forces Exit(_) to 0, but canonical.rs uses completed.iteration() to label post_capability and post_capability_resume. Any exit coming out of assistant_reply or capabilities will therefore be traced under iteration 0 instead of the live loop iteration. Carry the caller's current iteration through that trace boundary instead of encoding a sentinel here.
🤖 Prompt for AI Agents
Verify each finding against current code. Fix only still-valid issues, skip the
rest with a brief reason, keep changes minimal, and validate.
In `@crates/ironclaw_agent_loop/src/executor.rs` around lines 194 - 201, The
TurnCompletedStep::iteration helper is synthesizing a sentinel 0 for Exit, which
causes canonical.rs tracing to lose the live loop iteration when labeling
post_capability and post_capability_resume. Update TurnCompletedStep::iteration
and the callers around assistant_reply/capabilities so Exit carries or preserves
the current iteration from the caller/state instead of returning 0, and use that
value when emitting the trace boundary.
76034f0 to
1880fd8
Compare
|
🚅 Deployed to the ironclaw-pr-5487 environment in ironclaw-ci-preview
|
…ntaining "Secretary" aren't scrubbed as "secret" on replay — undoes #5902 tool-result eviction / re-fetch loop (+ 24KB/48KB caps) (#6129) * docs: add design spec for enabling Reborn nudges on 2 profiles Scopes allow_driver_specific_nudges to interactive_default and scheduled_trigger via a builder method, avoiding a shared-base flip that would leak into planned_default/subagent. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * docs: correct nudge-enable spec target from interactive_default to planned_default Real production interactive/chat/CLI turns request no explicit run profile (submit_user_turn passes requested_run_profile: None) and the production resolver defaults that to planned_default, not the literal interactive_profile() construct. Retargets the design accordingly and simplifies the implementation (no shared-base change needed at all). Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * docs: add implementation plan for enabling planned_default/scheduled_trigger nudges Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * docs: extract shared test helpers in nudge-enable plan per thermo-nuclear review Tasks 6/7 previously copy-pasted the same scripted scenario and completion assertion; extract no_progress_script()/ assert_completed_via_nudge() once, following the file's existing run_request/run_context_for_driver helper-extraction pattern. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * feat(ironclaw_turns): add RunProfileDefinition::with_driver_specific_nudges builder * Revert "feat(ironclaw_turns): add RunProfileDefinition::with_driver_specific_nudges builder" This reverts commit 326a16c. * docs: agent-loop canonical.rs slop cleanup design spec Scopes fix for two recurring anti-pattern instances (completion-nudge branching from #6013, latency-span boilerplate from #5487) plus a new guardrail rule file, per Slack discussion on ironclaw_agent_loop growth. * fix(threads): raise result_read preview/chunk cap to undo #5902 benchmark regression PR #5902 (fixing #5838's context-compaction crash) cut the model-visible tool-result preview from 100,000 to 2,048 bytes and capped result_read pagination at the same 2,048-byte chunk with no bulk-fetch option -- recovering a 100KB tool result now takes ~49 manual result_read calls, which most agent policies won't do reliably. This is a likely cause of the reported benchmark score regression. Raises TOOL_RESULT_RECORD_READ_MAX_BYTES to 40KB (still per-call bounded, which is the property #5838 actually needed -- unbounded accumulation in the compacted transcript caused the crash, not single-call size). Derives MAX_MODEL_OBSERVATION_BYTES from that constant (was an independent 4096 literal) so the whole-envelope validation cap can't silently fall behind the preview cap and start dropping large observations to bare summaries. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * fix(tests): size large-echo fixture against raised result_read cap TOOL_RESULT_RECORD_READ_MAX_BYTES was raised 2KiB -> 40KiB earlier in this PR; local_dev_runtime_safe_preview_observer_receives_bounded_payload used a hardcoded ~2.5KB fixture sized for the old cap, so it no longer exceeded the new cap and the truncation path it exercises stopped firing, failing the "raw tail must remain out of the model replay" assertion. Size the fixture relative to the cap instead, matching the fix already applied to the other 3 hardcoded-size fixtures in this PR. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> * fix(threads): word-boundary match for sensitive markers (undo "Secretary" scrub) The replay validator matched SENSITIVE/PROMPT_INJECTION markers as raw substrings, so `secret` matched the ordinary word `secretary`. Any tool result containing "Secretary of the Treasury" (i.e. every OfficeQA read, and PinchBench doc tasks) had its model-observation scrubbed on replay and fell back to a stub — evicting the content from the transcript and sending the model into a re-fetch loop (identical read/grep re-issued 16-26x, result_read storms, 3-10x calls/cost, timeouts). This is the residual #5902 regression the preview/observation cap bump alone did not fix. Match markers on word boundaries instead: a marker only trips as a standalone alphanumeric token. Delimiter-bounded markers (`bearer `, `authorization:`) and standalone credentials (`client secret`) still match. Verified on the two hardest-hit OfficeQA tasks (UID0072, UID0034): scrub events 16+/task -> 0, result_read 12-16 -> 0-2, calls 45-173 -> 18-29, score 0.0 -> 1.0, cost at/below pre-5902. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(threads): lower caps to 16KB/32KB + retention regression tests Follow-up on the same PR: - Preview cap 40KB -> 16KB and envelope cap derived as 2x (32KB). 40KB retained per result was too much context; 16KB holds a normal table read while staying bounded, and 32KB envelope comfortably fits a 16KB preview of ordinary text plus schema fields. - With the preview lower, more results overflow onto the result_read path, so the retention of paged content matters more. That path was never a separate bug: a result_read chunk's observation flows through the SAME normalize/validate scrub as the first-look preview, so the word-boundary marker fix already keeps paged chunks intact (confirmed: at 16KB, tasks page result_read and still resolve 1.0). No InlineOnly change needed. - Comprehensive retention tests so this can't regress: * document_content_preview_is_retained_on_replay_not_scrubbed — an 8KB "Secretary of the Treasury" preview stays intact through replay. * observation_envelope_cap_covers_the_preview_cap — structural guard that the envelope cap can never fall below the preview cap (the #5902 drift). * full_cap_preview_survives_replay — a max-size preview still fits. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * test(threads): pin result_read chunk retention + bump preview cap to 24KB - Add `result_read_chunk_observation_with_document_content_is_retained`: proves a paged result_read CHUNK observation (same shape result_read_observation emits) carrying "Secretary of the Treasury" survives replay intact, not scrubbed to a stub. Chunk observations run through the same normalize/scrub as first-look previews, so this pins that the paged-retrieval path ("get the rest") stays fixed too — the deterministic guarantee that paged content can't silently vanish. - Preview cap 16KB -> 24KB (envelope derives to 48KB). 16KB was tight enough that overflow-heavy reads paged hard; 24KB holds a normal multi-table read while staying bounded. Retention is guaranteed by the tests regardless of the exact cap; 24KB is the tuned middle. Deterministic coverage now spans all three retention failure modes: first-look preview (document_content_preview_is_retained...), paged chunk (this test), and envelope-vs-preview drift (observation_envelope_cap_covers_the_preview_cap). ironclaw_threads 82/82. Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com> * fix(threads): retain result-read previews on replay * fix(threads): satisfy replay CI guards --------- Co-authored-by: Claude Sonnet 5 <noreply@anthropic.com> Co-authored-by: Pranav Raja <pranav.raja@near.ai>
Summary
Change Type
Linked Issue
Security / DB Impact
Blast Radius
Rollback Plan
ironclaw_observabilitydependency fromironclaw_agent_loop.ironclaw_latency=tracelogging.Review Follow-Through
executor::latencyinstead of defining it locally incanonical.rs.Reborn Checklist
Validation
cargo fmt --checkcargo check -p ironclaw_agent_loop -p ironclaw_reborncargo test -p ironclaw_agent_loop --libgit diff --check