Skip to content

feat: Clarity eval hook call-tracing improvements#7401

Open
cylewitruk-stacks wants to merge 9 commits into
stacks-network:developfrom
cylewitruk-stacks:feat/clarity-eval-hook-tracing-improvements
Open

feat: Clarity eval hook call-tracing improvements#7401
cylewitruk-stacks wants to merge 9 commits into
stacks-network:developfrom
cylewitruk-stacks:feat/clarity-eval-hook-tracing-improvements

Conversation

@cylewitruk-stacks

@cylewitruk-stacks cylewitruk-stacks commented Jul 8, 2026

Copy link
Copy Markdown
Contributor

Adds opt-in Clarity VM hook support for structured call tracing.

Note for reviewers: most of this PR's diff is new tests.

Resolves: https://github.com/stx-labs/core-epics/issues/375

This PR extends EvalHook with:

  • top-level execution lifecycle notifications,
  • call begin / evaluated argument / call finish notifications,
  • call metadata for builtins, special forms, and user-defined functions,
  • begin-time argument payloads as either source expressions or pre-evaluated values, and
  • it also adds vm::hooks::trace::CallTraceHook, a reusable collector that reconstructs a call tree with resolved args, results, inclusive/exclusive execution cost, wall time, and nested calls. While fully functional (and public), it was largely used to verify the necessary functionality of the call-trace hooks themselves and serves as a good example for anyone needing to implement their own.

Why

stacks-bench and other replay tooling would benefit from understanding which logical VM calls executed during historical transactions, what values they consumed/returned, and where cost was charged. Existing expression-level eval hooks are too low-level for this and require downstream tooling to duplicate VM call-resolution logic.

Notes

  • Hook APIs are grouped under vm::hooks.
  • Internal dispatch helpers remain crate-private.
  • did_complete remains unchanged; it is still an external/Clarinet-style completion hook, not emitted by the VM.
  • When no hooks are registered, call tracing stays on the existing near-zero overhead path.
  • This PR does not wire call-tracing through stackslib block/transaction-processing code (which is used by stacks-inspect and stacks-bench); that will be in a followup PR -- this is the clarity-side implementation.
  • EvalHook moved into the vm::hooks namespace (from a direct vm::EvalHook export, which will break existing consumers -- but it's a simple module path update). I chose to do this to avoid hooks types polluting the core vm namespace for opt-in functionality.

Testing

  • Added hook coverage for lifecycle events, lazy special forms, fold/step functions, trait-dispatched calls, nested contract calls, and state reads/writes visible through Clarity values.
Example output from the debug tracer in tests/hooks.rs: eval_hook_captures_nested_contract_calls_folding_over_contract_calls

Link to test

cargo nextest run -p clarity --nocapture eval_hook_captures_nested_contract_calls_folding_over_contract_calls

=== eval_hook_captures_nested_contract_calls_folding_over_contract_calls trace ===
𝑓(𝑥) "trace-top.entry" [public] (1 arg)
  𝑎₁ "seed" = u2
  𝑓(𝑥) "contract-call?" [builtin] (3 args)
    𝑓(𝑥) "list" [builtin] (3 args)
      𝑓(𝑥) "+" [builtin] (2 args)
        𝑎₁ "arg0" = u2
        𝑎₂ "arg1" = u1
      ⏎ "+" ⇒ u3
    ⏎ "list" ⇒ (u2 u3 u0)
    𝑓(𝑥) "trace-agg.sum-doubled" [public] (1 arg)
      𝑎₁ "items" = (u2 u3 u0)
      𝑓(𝑥) "ok" [builtin] (1 arg)
        𝑓(𝑥) "fold" [builtin] (3 args)
          𝑓(𝑥) "trace-agg.add-doubled" [private] (2 args)
            𝑎₁ "item" = u2
            𝑎₂ "acc" = u0
            𝑓(𝑥) "if" [builtin] (3 args)
              𝑓(𝑥) ">" [builtin] (2 args)
              ⏎ ">" ⇒ true
              𝑓(𝑥) "match" [builtin] (5 args)
                𝑓(𝑥) "contract-call?" [builtin] (3 args)
                  𝑓(𝑥) "trace-math.double" [public] (1 arg)
                    𝑎₁ "n" = u2
                    𝑓(𝑥) "if" [builtin] (3 args)
                      𝑓(𝑥) ">" [builtin] (2 args)
                      ⏎ ">" ⇒ false
                      𝑓(𝑥) "ok" [builtin] (1 arg)
                        𝑓(𝑥) "*" [builtin] (2 args)
                          𝑎₁ "arg0" = u2
                          𝑎₂ "arg1" = u2
                        ⏎ "*" ⇒ u4
                        𝑎₁ "arg0" = u4
                      ⏎ "ok" ⇒ (ok u4)
                    ⏎ "if" ⇒ (ok u4)
                  ⏎ "trace-math.double" ⇒ (ok u4)
                ⏎ "contract-call?" ⇒ (ok u4)
                𝑓(𝑥) "+" [builtin] (2 args)
                  𝑎₁ "arg0" = u0
                  𝑎₂ "arg1" = u4
                ⏎ "+" ⇒ u4
              ⏎ "match" ⇒ u4
            ⏎ "if" ⇒ u4
          ⏎ "trace-agg.add-doubled" ⇒ u4
          𝑓(𝑥) "trace-agg.add-doubled" [private] (2 args)
            𝑎₁ "item" = u3
            𝑎₂ "acc" = u4
            𝑓(𝑥) "if" [builtin] (3 args)
              𝑓(𝑥) ">" [builtin] (2 args)
              ⏎ ">" ⇒ true
              𝑓(𝑥) "match" [builtin] (5 args)
                𝑓(𝑥) "contract-call?" [builtin] (3 args)
                  𝑓(𝑥) "trace-math.double" [public] (1 arg)
                    𝑎₁ "n" = u3
                    𝑓(𝑥) "if" [builtin] (3 args)
                      𝑓(𝑥) ">" [builtin] (2 args)
                      ⏎ ">" ⇒ false
                      𝑓(𝑥) "ok" [builtin] (1 arg)
                        𝑓(𝑥) "*" [builtin] (2 args)
                          𝑎₁ "arg0" = u3
                          𝑎₂ "arg1" = u2
                        ⏎ "*" ⇒ u6
                        𝑎₁ "arg0" = u6
                      ⏎ "ok" ⇒ (ok u6)
                    ⏎ "if" ⇒ (ok u6)
                  ⏎ "trace-math.double" ⇒ (ok u6)
                ⏎ "contract-call?" ⇒ (ok u6)
                𝑓(𝑥) "+" [builtin] (2 args)
                  𝑎₁ "arg0" = u4
                  𝑎₂ "arg1" = u6
                ⏎ "+" ⇒ u10
              ⏎ "match" ⇒ u10
            ⏎ "if" ⇒ u10
          ⏎ "trace-agg.add-doubled" ⇒ u10
          𝑓(𝑥) "trace-agg.add-doubled" [private] (2 args)
            𝑎₁ "item" = u0
            𝑎₂ "acc" = u10
            𝑓(𝑥) "if" [builtin] (3 args)
              𝑓(𝑥) ">" [builtin] (2 args)
              ⏎ ">" ⇒ false
            ⏎ "if" ⇒ u10
          ⏎ "trace-agg.add-doubled" ⇒ u10
        ⏎ "fold" ⇒ u10
        𝑎₁ "arg0" = u10
      ⏎ "ok" ⇒ (ok u10)
    ⏎ "trace-agg.sum-doubled" ⇒ (ok u10)
  ⏎ "contract-call?" ⇒ (ok u10)
⏎ "trace-top.entry" ⇒ (ok u10)

=== eval_hook_captures_nested_contract_calls_folding_over_contract_calls call tree ===
(trace-top.entry seed=u2) ⇒ (ok u10)
    (contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-agg sum-doubled ( list seed ( + seed u1 ) u0 )) ⇒ (ok u10)
        (list seed ( + seed u1 ) u0) ⇒ (u2 u3 u0)
            (+ 𝑥(seed)=u2 u1) ⇒ u3
        (trace-agg.sum-doubled items=(u2 u3 u0)) ⇒ (ok u10)
            (ok 𝑓₁=u10) ⇒ (ok u10)
                (fold add-doubled items u0) ⇒ 𝑓₁=u10
                    (trace-agg.add-doubled item=u2 acc=u0) ⇒ u4
                        (if ( > item u0 ) ( match ( contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item ) doubled ( + acc doubled ) err-val acc ) acc) ⇒ u4
                            (> item u0) ⇒ 𝑓₂=true
                            (match ( contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item ) doubled ( + acc doubled ) err-val acc) ⇒ 𝑓₃=u4
                                (contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item) ⇒ 𝑓₄=(ok u4)
                                    (trace-math.double n=u2) ⇒ (ok u4)
                                        (if ( > n u100 ) ( err u1 ) ( ok ( * n u2 ) )) ⇒ (ok u4)
                                            (> n u100) ⇒ 𝑓₅=false
                                            (ok 𝑓₇=u4) ⇒ 𝑓₆=(ok u4)
                                                (* 𝑥(n)=u2 u2) ⇒ 𝑓₇=u4
                                (+ 𝑥(acc)=u0 𝑥(doubled)=u4) ⇒ 𝑓₈=u4
                    (trace-agg.add-doubled item=u3 acc=u4) ⇒ u10
                        (if ( > item u0 ) ( match ( contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item ) doubled ( + acc doubled ) err-val acc ) acc) ⇒ u10
                            (> item u0) ⇒ 𝑓₉=true
                            (match ( contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item ) doubled ( + acc doubled ) err-val acc) ⇒ 𝑓₁₀=u10
                                (contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item) ⇒ 𝑓₁₁=(ok u6)
                                    (trace-math.double n=u3) ⇒ (ok u6)
                                        (if ( > n u100 ) ( err u1 ) ( ok ( * n u2 ) )) ⇒ (ok u6)
                                            (> n u100) ⇒ 𝑓₁₂=false
                                            (ok 𝑓₁₄=u6) ⇒ 𝑓₁₃=(ok u6)
                                                (* 𝑥(n)=u3 u2) ⇒ 𝑓₁₄=u6
                                (+ 𝑥(acc)=u4 𝑥(doubled)=u6) ⇒ 𝑓₁₅=u10
                    (trace-agg.add-doubled item=u0 acc=u10) ⇒ u10
                        (if ( > item u0 ) ( match ( contract-call? S1G2081040G2081040G2081040G208105NK8PE5.trace-math double item ) doubled ( + acc doubled ) err-val acc ) acc) ⇒ u10
                            (> item u0) ⇒ 𝑓₁₆=false

Checklist

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR introduces an opt-in, higher-level Clarity VM hook API for structured call tracing (call begin/arg eval/call finish plus top-level lifecycle events), and adds a reusable CallTraceHook collector that reconstructs resolved call trees with timing and cost attribution. It also wires the new analysis-time budget parameter through block builder transaction-mining call sites to support per-tx analysis deadlines.

Changes:

  • Adds vm::hooks (new EvalHook surface + call tracing event model) and instruments the VM evaluator to emit structured call/lifecycle notifications.
  • Adds vm::hooks::trace::CallTraceHook to collect call trees with resolved args/results, inclusive/exclusive cost, and wall-clock timing.
  • Extends block-builder transaction mining to pass an additional per-tx max_analysis_time budget and updates affected call sites/tests.

Reviewed changes

Copilot reviewed 25 out of 25 changed files in this pull request and generated no comments.

Show a summary per file
File Description
stackslib/src/net/api/tests/postblock_proposal.rs Updates postblock proposal API tests to pass the new max_analysis_time argument when mining transactions.
stackslib/src/net/api/postblock_proposal.rs Adds per-tx analysis-time budgeting during proposal validation and threads the new argument through replay/validation mining calls.
stackslib/src/net/api/blockreplay.rs Updates replay mining call to include the new max_analysis_time argument.
stackslib/src/clarity_vm/tests/ephemeral.rs Updates ephemeral replay test mining call to include the new max_analysis_time argument.
stackslib/src/clarity_vm/clarity.rs Adjusts with_abort_callback signature/lifetimes to support hook-aware OwnedEnvironment usage.
stackslib/src/chainstate/tests/consensus.rs Updates test mining calls to include the new max_analysis_time argument.
stackslib/src/chainstate/stacks/tests/chain_histories.rs Updates helper mining calls to include the new max_analysis_time argument.
stackslib/src/chainstate/stacks/miner.rs Extends BlockBuilder APIs to accept max_analysis_time and threads miner settings through mining selection paths.
stackslib/src/chainstate/nakamoto/tests/node.rs Updates Nakamoto test mining calls to include the new max_analysis_time argument.
stackslib/src/chainstate/nakamoto/shadow.rs Updates shadow builder mining calls to include the new max_analysis_time argument.
stackslib/src/chainstate/nakamoto/miner.rs Removes builder-stored analysis deadline in favor of per-call max_analysis_time and forwards it through mining.
stackslib/src/chainstate/coordinator/tests.rs Updates coordinator test mining calls to include the new max_analysis_time argument.
stacks-node/src/tests/signer/v0/tenure_extend.rs Updates signer test mining call to include the new max_analysis_time argument.
stacks-node/src/tests/nakamoto_integrations.rs Updates integration test mining call to include the new max_analysis_time argument.
clarity/src/vm/tests/mod.rs Registers the new hooks test module.
clarity/src/vm/tests/hooks.rs Adds extensive unit tests covering lifecycle events, call tracing, lazy special forms, fold, trait dispatch, nested contract calls, and state reads/writes.
clarity/src/vm/mod.rs Moves EvalHook into vm::hooks, instruments eval/apply paths to emit call/lifecycle hook notifications, and refactors builtin dispatch representation.
clarity/src/vm/hooks/mod.rs Introduces the new public hook API: execution lifecycle + call begin/arg eval/finish notifications and supporting types.
clarity/src/vm/hooks/internals.rs Adds internal notifier plumbing (EvalHookNotifier) and a no-op CallTraceFrame wrapper for near-zero overhead when hooks are absent.
clarity/src/vm/hooks/trace.rs Implements CallTraceHook collector to reconstruct resolved call trees with cost/timing attribution and includes unit tests for cost math helpers.
clarity/src/vm/functions/mod.rs Refactors reserved function lookup to return CallableType::Builtin { clarity_name, kind } and supports call tracing metadata.
clarity/src/vm/contexts.rs Adds hook registration, execution lifecycle notifications, call tracing around entry/contract-call routing, and introduces FunctionExecutionOptions.
clarity/src/vm/clarity.rs Updates TransactionConnection::with_abort_callback signature to support hook-aware OwnedEnvironment<'_, 'hooks>.
clarity/src/vm/callables.rs Refactors callable representation to split builtins into CallableType::Builtin + BuiltinKind, adds call trace hook construction, and exposes function name/arg accessors.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

@cylewitruk-stacks

Copy link
Copy Markdown
Contributor Author

@hugo-stacks this would be a small breaking change for Clarinet -- worth a look by you guys.

Basically, the changes here provide deeper call tracing hooks which allow tx replayers (which use core "append block" flows) to instrument Clarity VM execution more accurately during block/tx replay.

@hugo-stacks

Copy link
Copy Markdown
Contributor

Thanks for the heads up @cylewitruk-stacks
Does it update the hook trait? (sorry the diff is hard to scan right now)

I'll keep an eye on it

@cylewitruk-stacks

Copy link
Copy Markdown
Contributor Author

Thanks for the heads up @cylewitruk-stacks
Does it update the hook trait? (sorry the diff is hard to scan right now)

I'll keep an eye on it

Yeah, it does (with new fn's with default impls). Behavior itself shouldn't be changed for the fn's Clarinet currently uses, but the trait moved into the vm::hooks module instead of just vm:: (hence the breaking change).

@francesco-stacks

Copy link
Copy Markdown
Contributor

should this target develop instead?

@cylewitruk-stacks
cylewitruk-stacks changed the base branch from master to develop July 16, 2026 15:26

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 12 out of 12 changed files in this pull request and generated 2 comments.

Comment on lines +48 to +58
/// ```text
/// ▶ "trace-test.entry" [public] (1 arg)
/// 𝑎₁ (seed) = u0
/// ▶ "trace-test.foo" [private] (2 args)
/// ↳ eval 𝑎₁ (a)
/// ▶ "+" [builtin] (2 args)
/// ◀ "+" ⇒ u42
/// 𝑎₁ (a) = u42
/// ◀ "trace-test.foo" ⇒ u84
/// ◀ "trace-test.entry" ⇒ (ok u84)
/// ```
Comment on lines +60 to +64
/// Called when top-level execution completes.
///
/// **Note:** This is never called by the Clarity VM itself, however `clarinet` currently
/// implements it internally as part of its REPL interpreter.
fn did_complete(&mut self, _result: Result<&mut ExecutionResult, String>) {}
@coveralls

coveralls commented Jul 16, 2026

Copy link
Copy Markdown

Coverage Report for CI Build 29104084057

Coverage increased (+0.9%) to 86.541%

Details

  • Coverage increased (+0.9%) from the base build.
  • Patch coverage: 36 uncovered changes across 5 files (665 of 701 lines covered, 94.86%).
  • 10177 coverage regressions across 130 files.

Uncovered Changes

File Changed Covered %
clarity/src/vm/mod.rs 68 53 77.94%
clarity/src/vm/hooks/trace.rs 214 204 95.33%
clarity/src/vm/hooks/mod.rs 81 76 93.83%
clarity/src/vm/callables.rs 24 21 87.5%
clarity/src/vm/contexts.rs 142 139 97.89%
Total (8 files) 701 665 94.86%

Coverage Regressions

10177 previously-covered lines in 130 files lost coverage.

Top 10 Files by Coverage Loss Lines Losing Coverage Coverage
stackslib/src/chainstate/burn/db/sortdb.rs 637 90.45%
stackslib/src/chainstate/stacks/db/blocks.rs 537 89.82%
stackslib/src/chainstate/nakamoto/mod.rs 490 84.77%
stackslib/src/net/relay.rs 318 74.72%
stackslib/src/net/mod.rs 313 78.08%
stackslib/src/config/mod.rs 298 78.53%
stackslib/src/chainstate/stacks/db/transactions.rs 263 97.13%
stackslib/src/chainstate/stacks/index/storage.rs 263 82.41%
clarity/src/vm/database/structures.rs 247 77.65%
stackslib/src/chainstate/stacks/boot/mod.rs 245 94.28%

Coverage Stats

Coverage Status
Relevant Lines: 231832
Covered Lines: 200629
Line Coverage: 86.54%
Coverage Strength: 19469293.31 hits per line

💛 - Coveralls

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants