Verbosity System [Very Rough Draft]

lib/OrdinaryDiffEqCore/Project.toml

@@ -20,6 +20,7 @@ FunctionWrappersWrappers = "77dc65aa-8811-40c2-897b-53d922fa7daf"
 InteractiveUtils = "b77e0a4c-d291-57a0-90e8-8db25a27a240"
 LinearAlgebra = "37e2e46d-f89d-539d-b4ee-838fcccc9c8e"
 Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"
+LoggingExtras = "e6f89c97-d47a-5376-807f-9c37f3926c36"
 MacroTools = "1914dd2f-81c6-5fcd-8719-6d5c9610ff09"
 MuladdMacro = "46d2c3a1-f734-5fdb-9937-b9b9aeba4221"
 Polyester = "f517fe37-dbe3-4b94-8317-1923a5111588"
@@ -61,6 +62,7 @@ FunctionWrappersWrappers = "0.1"
 InteractiveUtils = "1.9"
 LinearAlgebra = "1.9"
 Logging = "1.9"
+LoggingExtras = "1.1.0"
 MacroTools = "0.5"
 MuladdMacro = "0.2.1"
 Polyester = "0.7"

lib/OrdinaryDiffEqCore/src/OrdinaryDiffEqCore.jl

@@ -149,6 +149,8 @@ include("solve.jl")
 include("initdt.jl")
 include("interp_func.jl")
 
+include("verbosity.jl")
+
 include("precompilation_setup.jl")
 
 end

lib/OrdinaryDiffEqCore/src/initdt.jl

@@ -127,8 +127,8 @@
     # Better than checking any(x->any(isnan, x), f₀)
     # because it also checks if partials are NaN
     # https://discourse.julialang.org/t/incorporating-forcing-functions-in-the-ode-model/70133/26
-    if integrator.opts.verbose && isnan(d₁)
-        @warn("First function call produced NaNs. Exiting. Double check that none of the initial conditions, parameters, or timespan values are NaN.")
+    if isnan(d₁)
+        integrator.opts.verbose("First function call produced NaNs. Exiting. Double check that none of the initial conditions, parameters, or timespan values are NaN.", :thing5, :numerical)
         return tdir * dtmin
     end
 
@@ -154,6 +154,10 @@
 
     u₁ = zero(u0) # required by DEDataArray
 
+    integrator.opts.verbose(:thing1, :error_control) do 
+        "message is $(tdir * dt₀)"
+    end
+
     if u0 isa Array
         @inbounds @simd ivdep for i in eachindex(u0)
             u₁[i] = u0[i] + dt₀_tdir * f₀[i]
@@ -175,6 +179,14 @@
     # Avoids AD issues
     length(u0) > 0 && f₀ == f₁ && return tdir * max(dtmin, 100dt₀)
 
+    integrator.opts.verbose(:thing3, :performance) do
+        if length(u0) > 0
+            "Length is greater than zero."
+        else 
+            "Length is zero."
+        end
+    end
+
     if u0 isa Array
         @inbounds @simd ivdep for i in eachindex(u0)
             tmp[i] = (f₁[i] - f₀[i]) / sk[i] * oneunit_tType
@@ -186,6 +198,10 @@
     d₂ = internalnorm(tmp, t) / dt₀ * oneunit_tType
     # Hairer has d₂ = sqrt(sum(abs2,tmp))/dt₀, note the lack of norm correction
 
+    integrator.opts.verbose("Some serious numerical issue!", :thing5, :numerical)
+
+    integrator.opts.verbose("Some other numerical issue!", :thing6, :numerical)
+
     max_d₁d₂ = max(d₁, d₂)
     if max_d₁d₂ <= 1 // Int64(10)^(15)
         dt₁ = max(convert(_tType, oneunit_tType * 1 // 10^(6)), dt₀ * 1 // 10^(3))

lib/OrdinaryDiffEqCore/src/integrators/type.jl

@@ -41,7 +41,7 @@ mutable struct DEOptions{absType, relType, QT, tType, Controller, F1, F2, F3, F4
     callback::F4
     isoutofdomain::F5
     unstable_check::F7
-    verbose::Bool
+    verbose
     calck::Bool
     force_dtmin::Bool
     advance_to_tstop::Bool

lib/OrdinaryDiffEqCore/src/solve.jl

@@ -54,7 +54,7 @@ function DiffEqBase.__init(
         internalopnorm = LinearAlgebra.opnorm,
         isoutofdomain = ODE_DEFAULT_ISOUTOFDOMAIN,
         unstable_check = ODE_DEFAULT_UNSTABLE_CHECK,
-        verbose = true,
+        verbose = ODEVerbosity(Verbosity.Default()),
         timeseries_errors = true,
         dense_errors = false,
         advance_to_tstop = false,

lib/OrdinaryDiffEqCore/src/verbosity.jl

@@ -0,0 +1,176 @@
+import SciMLBase
+import SciMLBase.@data
+import SciMLBase.@match
+using LoggingExtras
+
+@data Verbosity begin
+    None
+    Edge
+    Info
+    Warn
+    Error
+    All
+    Default
+    Level(Int)
+end
+
+
+mutable struct ODEErrorControlVerbosity
+    thing1::Any
+    thing2::Any
+end
+
+function ODEErrorControlVerbosity(verbose::Verbosity.Type)
+    @match verbose begin
+        Verbosity.None() => ODEErrorControlVerbosity(Verbosity.None(), Verbosity.None())
+
+        Verbosity.Warn() => ODEErrorControlVerbosity(Verbosity.Warn(), Verbosity.Warn())
+
+        Verbosity.Error() => ODEErrorControlVerbosity(Verbosity.Error(), Verbosity.Error())
+
+        Verbosity.Default() => ODEErrorControlVerbosity(Verbosity.Info(), Verbosity.Error())
+
+        Verbosity.Edge() => ODEErrorControlVerbosity(Verbosity.Info(), Verbosity.Warn())
+
+        _ => @error "Not a valid choice for verbosity."
+    end
+end
+
+mutable struct ODEPerformanceVerbosity
+    thing3::Any
+    thing4::Any
+end
+
+function ODEPerformanceVerbosity(verbose::Verbosity.Type)
+    @match verbose begin
+        Verbosity.None() => ODEPerformanceVerbosity(Verbosity.None(), Verbosity.None())
+
+        Verbosity.Warn() => ODEPerformanceVerbosity(Verbosity.Warn(), Verbosity.Warn())
+
+        Verbosity.Error() => ODEPerformanceVerbosity(Verbosity.Error(), Verbosity.Error())
+
+        Verbosity.Default() => ODEPerformanceVerbosity(Verbosity.Warn(), Verbosity.Error())
+
+        _ => @error "Not a valid choice for verbosity."
+    end
+end
+
+mutable struct ODENumericalVerbosity
+    thing5::Any
+    thing6::Any
+end
+
+function ODENumericalVerbosity(verbose::Verbosity.Type)
+    @match verbose begin
+        Verbosity.None() => ODENumericalVerbosity(Verbosity.None(), Verbosity.None())
+
+        Verbosity.Warn() => ODENumericalVerbosity(Verbosity.Warn(), Verbosity.Warn())
+
+        Verbosity.Error() => ODENumericalVerbosity(Verbosity.Error(), Verbosity.Error())
+
+        Verbosity.Default() => ODENumericalVerbosity(Verbosity.Warn(), Verbosity.Error())
+
+        _ => @error "Not a valid choice for verbosity."
+    end
+end
+
+struct ODEVerbosity{T}
+    error_control::Union{ODEErrorControlVerbosity, Nothing}
+    performance::Union{ODEPerformanceVerbosity, Nothing}
+    numerical::Union{ODENumericalVerbosity, Nothing}
+end
+
+function ODEVerbosity(verbose::Verbosity.Type)
+    @match verbose begin
+        Verbosity.Default() => ODEVerbosity{true}(
+            ODEErrorControlVerbosity(Verbosity.Default()),
+            ODEPerformanceVerbosity(Verbosity.Default()),
+            ODENumericalVerbosity(Verbosity.Default())
+        )
+
+        Verbosity.None() => ODEVerbosity{false}(nothing, nothing, nothing)
+
+        Verbosity.All() => ODEVerbosity{true}(
+            ODEErrorControlVerbosity(Verbosity.All()),
+            ODEPerformanceVerbosity(Verbosity.All()),
+            ODENumericalVerbosity(Verbosity.All())
+        )
+
+        _ => @error "Not a valid choice for verbosity."
+    end
+end
+
+function (verbose::ODEVerbosity{true})(message, option, group, values...)
+    level = get_message_level(verbose, option, group)
+
+    if !isnothing(level)
+        Base.@logmsg level message values
+    end
+end
+
+function (verbose::ODEVerbosity{true})(f::Function, option, group)
+    level = get_message_level(verbose, option, group)
+
+    if !isnothing(level)
+        message = f()
+        Base.@logmsg level message
+    end
+end
+
+function (verbose::ODEVerbosity{false})(f::Function, option, group)
+end
+
+function (verbose::ODEVerbosity{false})(message, option, group)
+end
+
+function get_message_level(verbose::ODEVerbosity{true}, option, group)
+    group = getproperty(verbose, group)
+    opt_level = getproperty(group, option)
+
+    @match opt_level begin
+        Verbosity.None() => nothing
+        Verbosity.Info() => Logging.Info
+        Verbosity.Warn() => Logging.Warn
+        Verbosity.Error() => Logging.Error
+        Verbosity.Level(i) => Logging.LogLevel(i)
+    end
+end
+
+function ODELogger(; info_repl = true, warn_repl = true, error_repl = true,
+        info_file = nothing, warn_file = nothing, error_file = nothing)
+    info_sink = isnothing(info_file) ? NullLogger() : FileLogger(info_file)
+    warn_sink = isnothing(warn_file) ? NullLogger() : FileLogger(warn_file)
+    error_sink = isnothing(error_file) ? NullLogger() : FileLogger(error_file)
+
+    repl_filter = EarlyFilteredLogger(current_logger()) do log
+        if log.level == Logging.Info && info_repl
+            return true
+        end
+
+        if log.level == Logging.Warn && warn_repl
+            return true
+        end
+
+        if log.level == Logging.Error && error_repl
+            return true
+        end
+
+        return false
+    end
+
+    info_filter = EarlyFilteredLogger(info_sink) do log
+        log.level == Logging.Info
+    end
+
+    warn_filter = EarlyFilteredLogger(warn_sink) do log
+        log.level == Logging.Warn
+    end
+
+    error_filter = EarlyFilteredLogger(error_sink) do log
+        log.level == Logging.Error
+    end
+
+    TeeLogger(repl_filter, info_filter, warn_filter, error_filter)
+end
+
+