SciMLLogging Integration

Project.toml

@@ -1,10 +1,11 @@
 name = "DelayDiffEq"
 uuid = "bcd4f6db-9728-5f36-b5f7-82caef46ccdb"
-authors = ["Chris Rackauckas <accounts@chrisrackauckas.com>"]
 version = "5.61.1"
+authors = ["Chris Rackauckas <accounts@chrisrackauckas.com>"]
 
 [deps]
 ArrayInterface = "4fba245c-0d91-5ea0-9b3e-6abc04ee57a9"
+ConcreteStructs = "2569d6c7-a4a2-43d3-a901-331e8e4be471"
 DataStructures = "864edb3b-99cc-5e75-8d2d-829cb0a9cfe8"
 DiffEqBase = "2b5f629d-d688-5b77-993f-72d75c75574e"
 FastBroadcast = "7034ab61-46d4-4ed7-9d0f-46aef9175898"
@@ -22,12 +23,14 @@ Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7"
 RecursiveArrayTools = "731186ca-8d62-57ce-b412-fbd966d074cd"
 Reexport = "189a3867-3050-52da-a836-e630ba90ab69"
 SciMLBase = "0bca4576-84f4-4d90-8ffe-ffa030f20462"
+SciMLLogging = "a6db7da4-7206-11f0-1eab-35f2a5dbe1d1"
 SimpleNonlinearSolve = "727e6d20-b764-4bd8-a329-72de5adea6c7"
 SimpleUnPack = "ce78b400-467f-4804-87d8-8f486da07d0a"
 SymbolicIndexingInterface = "2efcf032-c050-4f8e-a9bb-153293bab1f5"
 
 [compat]
 ArrayInterface = "7"
+ConcreteStructs = "0.2.3"
 DataStructures = "0.18, 0.19"
 DiffEqBase = "6.187"
 FastBroadcast = "0.3.5"
@@ -45,6 +48,7 @@ Printf = "1"
 RecursiveArrayTools = "3"
 Reexport = "1.0"
 SciMLBase = "2.115.0"
+SciMLLogging = "1.4.0"
 SimpleNonlinearSolve = "2"
 SimpleUnPack = "1"
 SymbolicIndexingInterface = "0.3.36"

src/DelayDiffEq.jl

@@ -28,7 +28,7 @@ import FastBroadcast: @..
 
 using OrdinaryDiffEqNonlinearSolve: NLAnderson, NLFunctional
 using OrdinaryDiffEqCore: AbstractNLSolverCache, SlowConvergence,
-                          alg_extrapolates, alg_maximum_order, initialize!
+                          alg_extrapolates, alg_maximum_order, initialize!, ODEVerbosity
 using OrdinaryDiffEqRosenbrock: RosenbrockMutableCache
 using OrdinaryDiffEqFunctionMap: FunctionMap
 # using OrdinaryDiffEqDifferentiation: resize_grad_config!, resize_jac_config!
@@ -49,13 +49,17 @@ using SciMLBase: CallbackSet, DAEProblem, DDEProblem, DESolution, ODEProblem, Re
                  change_t_via_interpolation!, isadaptive
 using DiffEqBase: initialize!
 import DiffEqBase
+using ConcreteStructs: @concrete
+using SciMLLogging: AbstractVerbositySpecifier, AbstractVerbosityPreset, AbstractMessageLevel, None, Minimal, Standard, Detailed, All,
+                    Silent, DebugLevel, InfoLevel, WarnLevel, ErrorLevel, @SciMLMessage
 
 import SciMLBase
 
 export Discontinuity, MethodOfSteps
 
 include("discontinuity_type.jl")
 include("functionwrapper.jl")
+include("verbosity.jl")
 
 include("integrators/type.jl")
 include("integrators/utils.jl")

src/fpsolve/fpsolve.jl

@@ -9,6 +9,11 @@ function SciMLBase.postamble!(fpsolver::FPSolver, integrator::DDEIntegrator)
 
     if OrdinaryDiffEqNonlinearSolve.nlsolvefail(fpsolver)
         integrator.stats.nfpconvfail += 1
+        @SciMLMessage(lazy"Fixed-point iteration failed to converge at t = $(integrator.t) after $(fpsolver.iter) iterations",
+            integrator.opts.verbose, :residual_control)
+    else
+        @SciMLMessage(lazy"Fixed-point iteration converged at t = $(integrator.t) in $(fpsolver.iter) iterations",
+            integrator.opts.verbose, :residual_control)
     end
     integrator.force_stepfail = OrdinaryDiffEqNonlinearSolve.nlsolvefail(fpsolver) ||
                                 integrator.force_stepfail

src/fpsolve/functional.jl

@@ -111,7 +111,10 @@ function compute_step_fixedpoint!(
     DiffEqBase.calculate_residuals!(atmp, dz, ode_integrator.u, integrator.u,
         opts.abstol, opts.reltol, opts.internalnorm, t)
 
-    opts.internalnorm(atmp, t)
+    residual = opts.internalnorm(atmp, t)
+    @SciMLMessage(lazy"Fixed-point iteration residual = $residual at t = $t",
+        opts.verbose, :residual_control)
+    residual
 end
 
 ## resize!

src/integrators/utils.jl

@@ -189,6 +189,10 @@ function OrdinaryDiffEqCore.handle_discontinuities!(integrator::DDEIntegrator)
     d = OrdinaryDiffEqCore.pop_discontinuity!(integrator)
     order = d.order
     tdir_t = integrator.tdir * integrator.t
+
+    @SciMLMessage(lazy"Handling discontinuity at t = $(integrator.t) with order $order",
+        integrator.opts.verbose, :discontinuity_tracking)
+
     while OrdinaryDiffEqCore.has_discontinuity(integrator) &&
         OrdinaryDiffEqCore.first_discontinuity(integrator) == tdir_t
         d2 = OrdinaryDiffEqCore.pop_discontinuity!(integrator)
@@ -234,6 +238,14 @@ function add_next_discontinuities!(integrator, order, t = integrator.t)
     neutral = integrator.sol.prob.neutral
     next_order = neutral ? order : order + 1
 
+    if neutral
+        @SciMLMessage(lazy"Adding next discontinuities for neutral DDE: order remains $order",
+            integrator.opts.verbose, :neutral_delay)
+    else
+        @SciMLMessage(lazy"Adding next discontinuities: order increases from $order to $next_order",
+            integrator.opts.verbose, :discontinuity_tracking)
+    end
+
     # only track discontinuities up to order of the applied method
     alg_maximum_order = OrdinaryDiffEqCore.alg_maximum_order(integrator.alg)
     next_order <= alg_maximum_order + 1 || return

src/solve.jl

@@ -75,7 +75,7 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
         internalopnorm = opnorm,
         isoutofdomain = DiffEqBase.ODE_DEFAULT_ISOUTOFDOMAIN,
         unstable_check = DiffEqBase.ODE_DEFAULT_UNSTABLE_CHECK,
-        verbose = true,
+        verbose = DDEVerbosity(),
         timeseries_errors = true,
         dense_errors = false,
         advance_to_tstop = false,
@@ -103,6 +103,19 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
         order_discontinuity_t0 = prob.order_discontinuity_t0
     end
 
+    # Handle verbose argument: convert Bool or AbstractVerbosityPreset to DDEVerbosity
+    if verbose isa Bool
+        if verbose
+            verbose_spec = DDEVerbosity()
+        else
+            verbose_spec = DDEVerbosity(None())
+        end
+    elseif verbose isa AbstractVerbosityPreset
+        verbose_spec = DDEVerbosity(verbose)
+    else
+        verbose_spec = verbose
+    end
+
     if alg.alg isa CompositeAlgorithm && alg.alg.choice_function isa AutoSwitch
         auto = alg.alg.choice_function
         alg = MethodOfSteps(CompositeAlgorithm(alg.alg.algs,
@@ -147,7 +160,13 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
     # no fixed-point iterations for constrained algorithms,
     # and thus `dtmax` should match minimal lag
     if isconstrained(alg) && has_constant_lags(prob)
-        dtmax = tdir * min(abs(dtmax), minimum(abs, constant_lags))
+        min_lag = minimum(abs, constant_lags)
+        old_dtmax = abs(dtmax)
+        dtmax = tdir * min(old_dtmax, min_lag)
+        if min_lag < old_dtmax
+            @SciMLMessage(lazy"Constrained algorithm: limiting dtmax from $old_dtmax to $min_lag (minimum lag)",
+                verbose_spec, :constrained_step)
+        end
     end
 
     # get absolute and relative tolerances
@@ -197,7 +216,7 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
         uBottomEltypeNoUnits, tTypeNoUnits, uprev, uprev2,
         f_with_history, t0, zero(tType), reltol_internal, p,
         calck,
-        Val(isinplace(prob)))
+        Val(isinplace(prob)), OrdinaryDiffEqCore.ODEVerbosity())
 
     # separate statistics of the integrator and the history
     stats = SciMLBase.DEStats(0)
@@ -294,7 +313,7 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
             typeof(d_discontinuities_internal), typeof(userdata),
             typeof(save_idxs),
             typeof(maxiters), typeof(tstops),
-            typeof(saveat), typeof(d_discontinuities), typeof(verbose)}(maxiters,
+            typeof(saveat), typeof(d_discontinuities), typeof(verbose_spec)}(maxiters,
             save_everystep,
             adaptive,
             abstol_internal,
@@ -335,7 +354,7 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
             callback_set,
             isoutofdomain,
             unstable_check,
-            verbose,
+            verbose_spec,
             calck,
             force_dtmin,
             advance_to_tstop,
@@ -394,7 +413,7 @@ function SciMLBase.__init(prob::SciMLBase.AbstractDDEProblem,
             callback_set,
             isoutofdomain,
             unstable_check,
-            verbose,
+            verbose_spec,
             calck,
             force_dtmin,
             advance_to_tstop,

src/track.jl

@@ -10,6 +10,9 @@ function track_propagated_discontinuities!(integrator::DDEIntegrator)
     interp_points = integrator.discontinuity_interp_points
     Θs = range(zero(integrator.t); stop = oneunit(integrator.t), length = interp_points)
 
+    @SciMLMessage(lazy"Tracking discontinuities for state-dependent delays in interval [$(integrator.t), $(integrator.t + integrator.dt)]",
+        integrator.opts.verbose, :state_dependent_delay)
+
     # for dependent lags and previous discontinuities
     for lag in integrator.sol.prob.dependent_lags,
         discontinuity in integrator.tracked_discontinuities
@@ -28,8 +31,12 @@ function track_propagated_discontinuities!(integrator::DDEIntegrator)
             # add new discontinuity of correct order at the estimated time point
             if integrator.sol.prob.neutral
                 d = Discontinuity(t, discontinuity.order)
+                @SciMLMessage(lazy"Propagated discontinuity found at t = $t with order $(discontinuity.order) (neutral DDE)",
+                    integrator.opts.verbose, :discontinuity_tracking)
             else
                 d = Discontinuity(t, discontinuity.order + 1)
+                @SciMLMessage(lazy"Propagated discontinuity found at t = $t with order $(discontinuity.order + 1)",
+                    integrator.opts.verbose, :discontinuity_tracking)
             end
             push!(integrator.opts.d_discontinuities, d)
             push!(integrator.opts.tstops, t)
@@ -60,7 +67,11 @@ function discontinuity_function(integrator::DDEIntegrator, lag, T, t)
         ut = cache
     end
 
-    T + lag(ut, integrator.p, t) - t
+    lag_value = lag(ut, integrator.p, t)
+    @SciMLMessage(lazy"Evaluating state-dependent delay at t = $t: lag = $lag_value",
+        integrator.opts.verbose, :delay_evaluation)
+
+    T + lag_value - t
 end
 
 """

src/utils.jl

@@ -298,7 +298,7 @@ function build_history_function(prob, alg, rate_prototype, reltol, differential_
         uBottomEltypeNoUnits, tTypeNoUnits, ode_uprev,
         ode_uprev, ode_f, t0, zero(tType), reltol, p,
         calck,
-        Val(isinplace(prob)))
+        Val(isinplace(prob)), OrdinaryDiffEqCore.ODEVerbosity())
 
     # build dense interpolation of history
     ode_alg_choice = iscomposite(alg) ? Int[] : nothing