Add more logging for run_ad

[penelopeysm]

Closes #1166. Example code which you can run is here. On main, these will both print out gigantic ugly structs using their default display methods.

using DynamicPPL, Distributions, ADTypes, FiniteDifferences, ForwardDiff, Random
using DynamicPPL.TestUtils.AD: run_ad, ADResult, WithBackend

ref_adtype = AutoFiniteDifferences(fdm=central_fdm(5, 1))
adtype = AutoForwardDiff()

@model function f()
    a ~ Normal()
    2.0 ~ Normal(a)
end
model = f()

# This is an example of a successful test.
run_ad(model, adtype; rng=Xoshiro(468), test=WithBackend(ref_adtype), benchmark=true)

# This is an example of a "failed" test (rtol should never be set to be so small).
run_ad(model, adtype; rng=Xoshiro(468), test=WithBackend(ref_adtype), rtol=eps())

The successful test now outputs the following. The lines up until ADResult are logging generated during the call itself (which can be disabled with verbose=true), after that it's the display method of the ADResult struct.

julia> run_ad(model, adtype; rng=Xoshiro(468), test=WithBackend(ref_adtype), benchmark=true)
[ Info: Running AD on f with AutoForwardDiff()
       params : [0.07200886749732076]
       actual : (-3.699044608412951, [1.8559822650053586])
     expected : (-3.699044608412951, [1.8559822650053162])
   evaluation : 11.871 ns (1 allocs: 32 bytes)
     gradient : 48.126 ns (4 allocs: 144 bytes)
  grad / eval : 4.054
ADResult
  ├ model          : f
  ├ adtype         : AutoForwardDiff()
  ├ value_actual   : -3.699044608412951
  ├ value_expected : -3.699044608412951
  ├ grad_actual    : [1.8559822650053586]
  ├ grad_expected  : [1.8559822650053162]
  ├ grad_time      : 4.812606473594549e-8 s
  ├ primal_time    : 1.1870939420544339e-8 s
  └ params         : [0.07200886749732076]

This is the failing test, it now tells you how much of an atol/rtol you need to make it pass, which is really useful for figuring out whether you have a serious correctness issue, or whether finite differences are just a bit inaccurate (I've needed to do this for ADTests a few times).

julia> run_ad(model, adtype; rng=Xoshiro(468), test=WithBackend(ref_adtype), rtol=eps())
[ Info: Running AD on f with AutoForwardDiff()
       params : [0.07200886749732076]
       actual : (-3.699044608412951, [1.8559822650053586])
     expected : (-3.699044608412951, [1.8559822650053162])
ERROR: ADIncorrectException: The AD backend returned an incorrect gradient.
  Testing was carried out with
               atol : 2.220446049250313e-14
               rtol : 2.220446049250313e-16
  The gradient check failed because:
      expected grad : [1.8559822650053586]
        actual grad : [1.8559822650053162]
  The gradient correctness check would have passed if either:
               atol ≥ 4.241051954068098e-14, or
               rtol ≥ 2.2850713792008425e-14

Stacktrace:
 [1] (::DynamicPPL.TestUtils.AD.var"#exc#4"{Float64, Float64, Float64})()
   @ DynamicPPL.TestUtils.AD ~/ppl/dppl/src/test_utils/ad.jl:369
 [2] run_ad(model::Model{…}, adtype::AutoForwardDiff{…}; test::WithBackend{…}, benchmark::Bool, atol::Float64, rtol::Float64, getlogdensity::Function, rng::Xoshiro, varinfo::VarInfo{…}, params::Nothing, verbose::Bool)
   @ DynamicPPL.TestUtils.AD ~/ppl/dppl/src/test_utils/ad.jl:371
 [3] top-level scope
   @ REPL[8]:1
Some type information was truncated. Use `show(err)` to see complete types.

[github-actions]

Benchmark Report

• this PR's head: 1b0e43bfce849065450940577338e535a35545cc
• base branch: 06ab8101e1bc5f3f8301f66b80780f7e302e0015

Computer Information

Julia Version 1.11.7
Commit f2b3dbda30a (2025-09-08 12:10 UTC)
Build Info:
  Official https://julialang.org/ release
Platform Info:
  OS: Linux (x86_64-linux-gnu)
  CPU: 4 × AMD EPYC 7763 64-Core Processor
  WORD_SIZE: 64
  LLVM: libLLVM-16.0.6 (ORCJIT, znver3)
Threads: 1 default, 0 interactive, 1 GC (on 4 virtual cores)

Benchmark Results

┌───────────────────────┬───────┬─────────────┬───────────────────┬────────┬────────────────────────────────┬────────────────────────────┬─────────────────────────────────┐
│                       │       │             │                   │        │        t(eval) / t(ref)        │     t(grad) / t(eval)      │        t(grad) / t(ref)         │
│                       │       │             │                   │        │ ──────────┬──────────┬──────── │ ───────┬─────────┬──────── │ ──────────┬───────────┬──────── │
│                 Model │   Dim │  AD Backend │           VarInfo │ Linked │      base │  this PR │ speedup │   base │ this PR │ speedup │      base │   this PR │ speedup │
├───────────────────────┼───────┼─────────────┼───────────────────┼────────┼───────────┼──────────┼─────────┼────────┼─────────┼─────────┼───────────┼───────────┼─────────┤
│               Dynamic │    10 │    mooncake │             typed │   true │    376.77 │   346.23 │    1.09 │   9.90 │    9.31 │    1.06 │   3728.28 │   3224.77 │    1.16 │
│                   LDA │    12 │ reversediff │             typed │   true │   2566.65 │  2433.68 │    1.05 │   5.13 │    4.98 │    1.03 │  13157.93 │  12113.62 │    1.09 │
│   Loop univariate 10k │ 10000 │    mooncake │             typed │   true │ 105024.63 │ 95451.89 │    1.10 │   4.11 │    4.02 │    1.02 │ 431275.48 │ 384101.50 │    1.12 │
├───────────────────────┼───────┼─────────────┼───────────────────┼────────┼───────────┼──────────┼─────────┼────────┼─────────┼─────────┼───────────┼───────────┼─────────┤
│    Loop univariate 1k │  1000 │    mooncake │             typed │   true │   7999.98 │  7188.27 │    1.11 │   4.92 │    4.85 │    1.01 │  39344.91 │  34837.80 │    1.13 │
│      Multivariate 10k │ 10000 │    mooncake │             typed │   true │  31895.61 │ 29787.23 │    1.07 │  10.33 │   10.16 │    1.02 │ 329528.35 │ 302705.80 │    1.09 │
│       Multivariate 1k │  1000 │    mooncake │             typed │   true │   3655.39 │  3316.66 │    1.10 │  12.91 │   12.93 │    1.00 │  47191.45 │  42894.65 │    1.10 │
├───────────────────────┼───────┼─────────────┼───────────────────┼────────┼───────────┼──────────┼─────────┼────────┼─────────┼─────────┼───────────┼───────────┼─────────┤
│ Simple assume observe │     1 │ forwarddiff │             typed │  false │      2.69 │     2.49 │    1.08 │   3.98 │    3.93 │    1.01 │     10.70 │      9.80 │    1.09 │
│           Smorgasbord │   201 │ forwarddiff │             typed │  false │   1228.52 │  1123.17 │    1.09 │  64.45 │   61.22 │    1.05 │  79173.93 │  68760.31 │    1.15 │
│           Smorgasbord │   201 │ forwarddiff │       simple_dict │   true │       err │      err │     err │    err │     err │     err │       err │       err │     err │
├───────────────────────┼───────┼─────────────┼───────────────────┼────────┼───────────┼──────────┼─────────┼────────┼─────────┼─────────┼───────────┼───────────┼─────────┤
│           Smorgasbord │   201 │ forwarddiff │ simple_namedtuple │   true │       err │      err │     err │    err │     err │     err │       err │       err │     err │
│           Smorgasbord │   201 │      enzyme │             typed │   true │   1666.35 │  1525.41 │    1.09 │   5.98 │    5.96 │    1.00 │   9966.20 │   9097.51 │    1.10 │
│           Smorgasbord │   201 │    mooncake │             typed │   true │   1678.20 │  1540.59 │    1.09 │   5.41 │    5.31 │    1.02 │   9081.53 │   8175.50 │    1.11 │
├───────────────────────┼───────┼─────────────┼───────────────────┼────────┼───────────┼──────────┼─────────┼────────┼─────────┼─────────┼───────────┼───────────┼─────────┤
│           Smorgasbord │   201 │ reversediff │             typed │   true │   1663.11 │  1527.61 │    1.09 │  90.95 │   92.26 │    0.99 │ 151268.00 │ 140943.91 │    1.07 │
│           Smorgasbord │   201 │ forwarddiff │      typed_vector │   true │   1678.95 │  1523.24 │    1.10 │  57.73 │   57.24 │    1.01 │  96933.59 │  87194.63 │    1.11 │
│           Smorgasbord │   201 │ forwarddiff │           untyped │   true │   1670.30 │  1529.82 │    1.09 │ 119.71 │  118.84 │    1.01 │ 199952.52 │ 181801.80 │    1.10 │
├───────────────────────┼───────┼─────────────┼───────────────────┼────────┼───────────┼──────────┼─────────┼────────┼─────────┼─────────┼───────────┼───────────┼─────────┤
│           Smorgasbord │   201 │ forwarddiff │    untyped_vector │   true │   1669.43 │  1545.72 │    1.08 │  55.14 │   53.94 │    1.02 │  92059.79 │  83374.42 │    1.10 │
│              Submodel │     1 │    mooncake │             typed │   true │      7.20 │     6.61 │    1.09 │   5.33 │    5.32 │    1.00 │     38.38 │     35.19 │    1.09 │
└───────────────────────┴───────┴─────────────┴───────────────────┴────────┴───────────┴──────────┴─────────┴────────┴─────────┴─────────┴───────────┴───────────┴─────────┘

[codecov]

Codecov Report

❌ Patch coverage is 1.81818% with 54 lines in your changes missing coverage. Please review.
✅ Project coverage is 35.34%. Comparing base (06ab810) to head (1b0e43b).
⚠️ Report is 1 commits behind head on main.

Files with missing lines	Patch %	Lines
src/test_utils/ad.jl	1.81%	54 Missing ⚠️

❗ There is a different number of reports uploaded between BASE (06ab810) and HEAD (1b0e43b). Click for more details.

HEAD has 6 uploads less than BASE

Flag	BASE (06ab810)	HEAD (1b0e43b)
	12	6

Additional details and impacted files

@@             Coverage Diff             @@
##             main    #1168       +/-   ##
===========================================
- Coverage   80.01%   35.34%   -44.67%     
===========================================
  Files          41       41               
  Lines        3877     3907       +30     
===========================================
- Hits         3102     1381     -1721     
- Misses        775     2526     +1751     

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

• ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

[github-actions]

DynamicPPL.jl documentation for PR #1168 is available at:
https://TuringLang.github.io/DynamicPPL.jl/previews/PR1168/

[mhauru]

LGTM

[penelopeysm]

(CI failures are unrelated)