Skip to content

Verbosity System [Very Rough Draft] #2688

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 2 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions lib/OrdinaryDiffEqCore/Project.toml
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down Expand Up @@ -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"
Expand Down
2 changes: 2 additions & 0 deletions lib/OrdinaryDiffEqCore/src/OrdinaryDiffEqCore.jl
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,8 @@ end
include("doc_utils.jl")
include("misc_utils.jl")

include("verbosity.jl")

include("algorithms.jl")
include("composite_algs.jl")

Expand Down
34 changes: 32 additions & 2 deletions lib/OrdinaryDiffEqCore/src/initdt.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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₁)
@SciMLMessage("First function call produced NaNs. Exiting. Double check that none of the initial conditions, parameters, or timespan values are NaN.", integrator.opts.verbose, :thing5, :numerical)
Copy link
Member

Choose a reason for hiding this comment

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

This isn't a numerical issue. It's an error or control flow one

return tdir * dtmin
end

Expand All @@ -154,6 +154,14 @@

u₁ = zero(u0) # required by DEDataArray

@SciMLMessage(integrator.opts.verbose, :thing1, :error_control) do
"u₁ is $u₁"
Copy link
Member

Choose a reason for hiding this comment

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

This doesn't make much sense to track

end

# 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]
Expand All @@ -175,6 +183,21 @@
# Avoids AD issues
length(u0) > 0 && f₀ == f₁ && return tdir * max(dtmin, 100dt₀)

@SciMLMessage(integrator.opts.verbose, :thing3, :performance) do
if length(u0) > 0
Copy link
Member

Choose a reason for hiding this comment

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

This isn't necessary

Copy link
Member Author

Choose a reason for hiding this comment

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

The specific messages here are more for demonstration purposes, I made some up to show that the macro works, this one demonstrates that you can write a do-block involving the outside variables and the result will be put in the log.

If it makes sense to do it this way, most of this stuff should be moved to SciMLBase and then we can start writing error messages using the macro.

Copy link
Member

Choose a reason for hiding this comment

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

The verbosity system looks right. I think we can start the move of the interface to SciMLBase

"Length is greater than zero."
else
"Length is zero."
end
end
# 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
Expand All @@ -186,6 +209,13 @@
d₂ = internalnorm(tmp, t) / dt₀ * oneunit_tType
# Hairer has d₂ = sqrt(sum(abs2,tmp))/dt₀, note the lack of norm correction

@SciMLMessage("Some serious numerical issue!", integrator.opts.verbose, :thing3, :performance)

#integrator.opts.verbose("Some serious numerical issue!", :thing5, :numerical)

@SciMLMessage("Some other numerical issue!", integrator.opts.verbose, :thing6, :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))
Expand Down
2 changes: 1 addition & 1 deletion lib/OrdinaryDiffEqCore/src/integrators/type.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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
Copy link
Member

Choose a reason for hiding this comment

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

Type stability

calck::Bool
force_dtmin::Bool
advance_to_tstop::Bool
Expand Down
2 changes: 1 addition & 1 deletion lib/OrdinaryDiffEqCore/src/solve.jl
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down
202 changes: 202 additions & 0 deletions lib/OrdinaryDiffEqCore/src/verbosity.jl
Original file line number Diff line number Diff line change
@@ -0,0 +1,202 @@
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
Copy link
Member

Choose a reason for hiding this comment

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

what's this?

Copy link
Member Author

Choose a reason for hiding this comment

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

There are only two uses of the verbose keyword in OrdinaryDiffEq so I had to make some up for demo purposes. In reality these will all be options that toggle error messages related to error control.

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 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


function emit_log(f::Function, verbose::ODEVerbosity{true}, option, group, file, line, _module)
level = message_level(verbose, option, group)

if !isnothing(level)
message = f()
Base.@logmsg level message _file = file _line = line _module = _module
end
end

function emit_log(message, verbose::ODEVerbosity{true}, option, group, file, line, _module)
level = message_level(verbose, option, group)

if !isnothing(level)
Base.@logmsg level message _file = file _line = line _module = _module
end
end

function emit_log(f, verbose::ODEVerbosity{false}, option, group, file, line, _module)
end

macro SciMLMessage(f, verb, toggle, group)
line = __source__.line
file = string(__source__.file)
_module = __module__
return :(emit_log($(esc(f)), $(esc(verb)), $toggle, $group, $file, $line, $_module))
end