Generic mechanism for debugging/logging functions

[hersle]

I find debug_system() very helpful for seeing where code generated by symbolics crashes. But it currently only handles a limited set of error types. It also duplicates domain-checking logic that must be added for every function that is to be debugged, so I think it scales poorly.

I propose this generic mechanism instead, which handles any error type, relies on the original functions' error/domain handling, and lets the user pass which functions they want debugged.

Checklist

• Appropriate tests were added
• Any code changes were done in a way that does not break public API
• All documentation related to code changes were updated
• The new code follows the
  contributor guidelines, in particular the SciML Style Guide and
  COLPRAC.
• Any new documentation only uses public API

[ChrisRackauckas]

Try catch can be quite expensive though, how much of an overhead does this have? It can be okay for a debug mode though

[hersle]

It actually seems free for an example that runs without errors, and better than the old behavior:

1. Save this spring-mass example to bench.jl (it has some "debuggable" division operations):

using ModelingToolkit, Plots, OrdinaryDiffEq, LinearAlgebra, BenchmarkTools
using ModelingToolkit: t_nounits as t, D_nounits as D
using Symbolics: scalarize

function Mass(; name, m = 1.0, xy = [0.0, 0.0], u = [0.0, 0.0])
    ps = @parameters m = m
    sts = @variables pos(t)[1:2]=xy v(t)[1:2]=u
    eqs = scalarize(D.(pos) .~ v)
    ODESystem(eqs, t, [pos..., v...], ps; name)
end

function Spring(; name, k = 1e4, l = 1.0)
    ps = @parameters k=k l=l
    @variables x(t), dir(t)[1:2]
    ODESystem(Equation[], t, [x, dir...], ps; name)
end

function connect_spring(spring, a, b)
    [spring.x ~ norm(scalarize(a .- b))
     scalarize(spring.dir .~ scalarize(a .- b))]
end

function spring_force(spring)
    -spring.k .* scalarize(spring.dir) .* (spring.x - spring.l) ./ spring.x
end

m = 1.0
xy = [1.0, -1.0]
k = 1e4
l = 1.0
center = [0.0, 0.0]
g = [0.0, -9.81]
@named mass = Mass(m = m, xy = xy)
@named spring = Spring(k = k, l = l)

eqs = [connect_spring(spring, mass.pos, center)
       scalarize(D.(mass.v) .~ spring_force(spring) / mass.m .+ g)]

@named _model = ODESystem(eqs, t, [spring.x; spring.dir; mass.pos], [])
@named model = compose(_model, mass, spring)
sys = structural_simplify(model)

println("\nDebugging OFF, branch ", read(`git branch --show-current`, String))
prob = ODEProblem(sys, [], (0.0, 3.0))
bench = @benchmark solve(prob, Rosenbrock23())
display(bench)

println("\nDebugging ON, branch ", read(`git branch --show-current`, String))
dsys = debug_system(sys)
dprob = ODEProblem(dsys, [], (0.0, 3.0))
dbench = @benchmark solve(dprob, Rosenbrock23())
display(dbench)

2. Compare from the shell:

git checkout --quiet master && julia bench.jl
git checkout --quiet generic_logged_functions && julia bench.jl

3. Output:

Debugging OFF, branch master

BenchmarkTools.Trial: 2066 samples with 1 evaluation per sample.
 Range (min … max):  2.257 ms … 30.838 ms  ┊ GC (min … max): 0.00% … 91.47%
 Time  (median):     2.294 ms              ┊ GC (median):    0.00%
 Time  (mean ± σ):   2.411 ms ±  1.146 ms  ┊ GC (mean ± σ):  3.51% ±  6.86%

   ▂▆██▇▇▅▅▃▃▂▂▁           ▁▁  ▁            ▁    ▁           ▁
  ▅███████████████▇▇▇▆▆█▆▆▇███▆██▆▇▇█▆▄▄▅▅████▆█▇█▇▇▅▄▄▁▄▁▄▅ █
  2.26 ms      Histogram: log(frequency) by time     2.65 ms <

 Memory estimate: 546.52 KiB, allocs estimate: 10677.

Debugging ON, branch master

BenchmarkTools.Trial: 632 samples with 1 evaluation per sample.
 Range (min … max):  7.026 ms … 42.955 ms  ┊ GC (min … max): 0.00% … 79.87%
 Time  (median):     7.148 ms              ┊ GC (median):    0.00%
 Time  (mean ± σ):   7.913 ms ±  3.002 ms  ┊ GC (mean ± σ):  6.25% ± 11.68%

  █▂     ▃▂                                                   
  ██▄▁▁▄▄██▆▄▁▄▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▁▄▁▁▄▄▅▅▄▁▁▁▄ ▆
  7.03 ms      Histogram: log(frequency) by time       22 ms <

 Memory estimate: 3.62 MiB, allocs estimate: 129585.
Precompiling ModelingToolkit...
  2 dependencies successfully precompiled in 90 seconds. 299 already precompiled.

Debugging OFF, branch generic_logged_functions

BenchmarkTools.Trial: 2011 samples with 1 evaluation per sample.
 Range (min … max):  2.226 ms … 34.032 ms  ┊ GC (min … max): 0.00% … 92.39%
 Time  (median):     2.269 ms              ┊ GC (median):    0.00%
 Time  (mean ± σ):   2.476 ms ±  1.210 ms  ┊ GC (mean ± σ):  3.28% ±  6.48%

  ▄██▅▄▃▁      ▁▃    ▂▁                 ▃▅▂                ▁ ▁
  ████████▇▆▆████▇▄▅▄███▆▅▄▁▄▄▄▄▁▁▄▄▁▄▄▄████▇▆▆▁▁▄▆▅▆▁▁▁▁▁▆█ █
  2.23 ms      Histogram: log(frequency) by time     3.16 ms <

 Memory estimate: 546.52 KiB, allocs estimate: 10677.

Debugging ON, branch generic_logged_functions

BenchmarkTools.Trial: 2083 samples with 1 evaluation per sample.
 Range (min … max):  2.233 ms … 29.775 ms  ┊ GC (min … max): 0.00% … 91.23%
 Time  (median):     2.272 ms              ┊ GC (median):    0.00%
 Time  (mean ± σ):   2.399 ms ±  1.048 ms  ┊ GC (mean ± σ):  2.62% ±  5.50%

  ▄██▆▃▂     ▁▂▃▂▂   ▁▂▂▃▁                                   ▁
  ████████▇▆▅█████▅▆██████▅▅▄▅▁▄▆▄▅▁▁▁▁▄▁▁▆█▆▁▁▄▄▁▁▁▄▁▄▁▁▁▁▆ █
  2.23 ms      Histogram: log(frequency) by time     3.12 ms <

 Memory estimate: 546.52 KiB, allocs estimate: 10677.

If you have a more complicated example in mind, I can try it.

[hersle]

I added a short documentation page to help discover debug_system().

What do you think?

[hersle]

Format checker does not like this workaround to show errors in the documentation. Not sure if there is a better way to handle this :/

[hersle]

Never mind; @repl instead of @example got rid of the workaround. Documentation page now builds locally like this: