Skip to content

feat: Clarity eval hook call-tracing improvements#7401

Open
cylewitruk-stacks wants to merge 22 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 22 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 transaction execution (without a custom Clarity interpreter), 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 thread clarity/src/vm/tests/hooks.rs Outdated
Comment thread clarity/src/vm/hooks/mod.rs Outdated
@coveralls

coveralls commented Jul 16, 2026

Copy link
Copy Markdown

Coverage Report for CI Build 30105515860

Coverage increased (+0.9%) to 86.587%

Details

  • Coverage increased (+0.9%) from the base build.
  • Patch coverage: 47 uncovered changes across 7 files (1178 of 1225 lines covered, 96.16%).
  • 12154 coverage regressions across 169 files.

Uncovered Changes

File Changed Covered %
clarity/src/vm/mod.rs 69 54 78.26%
clarity/src/vm/hooks/trace.rs 214 204 95.33%
clarity/src/vm/hooks/testing/mod.rs 313 307 98.08%
clarity/src/vm/hooks/mod.rs 81 76 93.83%
clarity/src/vm/hooks/testing/render.rs 210 205 97.62%
clarity/src/vm/callables.rs 24 21 87.5%
clarity/src/vm/contexts.rs 142 139 97.89%
Total (10 files) 1225 1178 96.16%

Coverage Regressions

12154 previously-covered lines in 169 files lost coverage.

Top 10 Files by Coverage Loss Lines Losing Coverage Coverage
stackslib/src/chainstate/burn/db/sortdb.rs 643 90.45%
stackslib/src/chainstate/stacks/db/blocks.rs 559 89.96%
stackslib/src/chainstate/nakamoto/mod.rs 492 84.77%
stackslib/src/config/mod.rs 325 78.25%
stackslib/src/net/relay.rs 323 74.72%
stackslib/src/net/mod.rs 313 78.15%
stackslib/src/chainstate/stacks/index/storage.rs 289 82.01%
clarity/src/vm/database/clarity_db.rs 273 82.02%
stackslib/src/chainstate/stacks/db/transactions.rs 269 97.13%
stackslib/src/chainstate/stacks/miner.rs 264 83.38%

Coverage Stats

Coverage Status
Relevant Lines: 232453
Covered Lines: 201275
Line Coverage: 86.59%
Coverage Strength: 19255451.59 hits per line

💛 - Coveralls

Comment thread clarity/src/vm/hooks/internals.rs
Comment thread clarity/src/vm/tests/hooks.rs
brice-stacks
brice-stacks previously approved these changes Jul 23, 2026

@brice-stacks brice-stacks 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.

This looks great! I just requested one more test.

Comment on lines +1507 to +1511
if let Err(e) = self.global_context.roll_back() {
Err(e)
} else {
result
}

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.

This is the same semantically as before, just more verbose. Is this just a style refactor?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Good catch -- I missed to revert this after some mid-impl trial and error which at the time broke the implicit error coercion; will revert.

Comment thread clarity/src/vm/mod.rs
Comment on lines +311 to +319
cost_input_handle(args.as_slice())
} else {
args.len() as u64
Ok(args.len() as u64)
};
runtime_cost(cost_function.clone(), exec_state, cost_input)
.map_err(VmExecutionError::from)
.and_then(|_| function.apply(args, exec_state, invoke_ctx))
cost_input.and_then(|cost_input| {
runtime_cost(cost_function.clone(), exec_state, cost_input)
.map_err(VmExecutionError::from)
.and_then(|_| function.apply(args, exec_state, invoke_ctx))
})

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.

This refactor makes the control flow of the error path much less clear to me -- I think early returning the error rather than passing it through the chained and_then is preferable.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

I'll re-read through this 👍

Comment thread clarity/src/vm/mod.rs
&args,
FunctionExecutionOptions::default(),
),
},

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.

This match feels like it should be defined elsewhere than within this larger match -- before your changeset, I suppose this logic lived in DefinedFunction::apply. It still feels like this match should live in its own function -- nesting matches seems like something to avoid.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

I did go back and forth on this several times, between larger match vs. more indirection... I'll read this over again and give a fresh opinion.

@aaronb-stacks aaronb-stacks 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.

This looks mostly good to me, just had a couple comments on some of the code refactoring.

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.

7 participants