From 11facf18573e689779216328170fd3c1127efe38 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Wed, 15 Oct 2025 16:41:26 -0400 Subject: [PATCH 01/23] add logging file --- src/AlgorithmsInterface.jl | 1 + src/logging.jl | 1 + 2 files changed, 2 insertions(+) create mode 100644 src/logging.jl diff --git a/src/AlgorithmsInterface.jl b/src/AlgorithmsInterface.jl index 8dd052a..8467abf 100644 --- a/src/AlgorithmsInterface.jl +++ b/src/AlgorithmsInterface.jl @@ -16,6 +16,7 @@ include("interface/state.jl") include("interface/interface.jl") include("stopping_criterion.jl") +include("logging.jl") export Algorithm, Problem, State export StoppingCriterion, StoppingCriterionState diff --git a/src/logging.jl b/src/logging.jl new file mode 100644 index 0000000..8b13789 --- /dev/null +++ b/src/logging.jl @@ -0,0 +1 @@ + From 2d740b87099dad90f4500fc6f579f12998b9b960 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 16 Oct 2025 07:54:32 -0400 Subject: [PATCH 02/23] add logging statements --- src/interface/interface.jl | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/interface/interface.jl b/src/interface/interface.jl index c72c8ca..63b5fe0 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -44,10 +44,14 @@ All keyword arguments are passed to the [`initialize_state!`](@ref)`(problem, al """ function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) initialize_state!(problem, algorithm, state; kwargs...) + log_start!(problem, algorithm, state) while !is_finished!(problem, algorithm, state) + log_before_iteration!(problem, algorithm, state) increment!(state) step!(problem, algorithm, state) + log_after_iteration!(problem, algorithm, state) end + log_stop!(problem, algorithm, state) return state end From 81c23a100e30faaba46cd7fed6ccca94d9bc7f61 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 16 Oct 2025 18:28:58 -0400 Subject: [PATCH 03/23] some progress --- src/interface/interface.jl | 8 +-- src/logging.jl | 126 +++++++++++++++++++++++++++++++++++++ 2 files changed, 130 insertions(+), 4 deletions(-) diff --git a/src/interface/interface.jl b/src/interface/interface.jl index 63b5fe0..866b3a2 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -44,14 +44,14 @@ All keyword arguments are passed to the [`initialize_state!`](@ref)`(problem, al """ function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) initialize_state!(problem, algorithm, state; kwargs...) - log_start!(problem, algorithm, state) + log!(problem, algorithm, state; context = :Start) while !is_finished!(problem, algorithm, state) - log_before_iteration!(problem, algorithm, state) + log!(problem, algorithm, state; context = :PreStep) increment!(state) step!(problem, algorithm, state) - log_after_iteration!(problem, algorithm, state) + log!(problem, algorithm, state; context = :PostStep) end - log_stop!(problem, algorithm, state) + log!(problem, algorithm, state; context = :Stop) return state end diff --git a/src/logging.jl b/src/logging.jl index 8b13789..9429349 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -1 +1,127 @@ +""" + log!(problem::Problem, algorithm::Algorithm, state::State; context::Symbol) -> nothing +Generate a log record for the given `(problem, algorithm, state)`, using the logging action associated to `context`. +By default, the following events trigger a logging action with the given `context`: + +| context | event | +| --------- | ------------------------------------- | +| :Start | The solver has been initialized. | +| :PreStep | The solver is about to take a step. | +| :PostStep | The solver has taken a step. | +| :Stop | The solver has finished. | + +Specific algorithms can associate other events with other contexts. + +See also [`register_action!`](@ref) to associate custom actions with these contexts. +""" +function log!(problem::Problem, algorithm::Algorithm, state::State; context)::Nothing + action = @something(logging_action(problem, algorithm, state, context), return nothing) + # TODO: filter out `nothing` logdata + @logmsg( + loglevel(action), logdata!(action, problem, algorithm, state), + _id = logid(action), _group = loggroup(algorithm) + ) + return nothing +end + +""" + logging_action(problem::Problem, algorithm::Algorithm, state::State, context::Symbol) + -> Union{Nothing,LoggingAction} + +Obtain the registered logging action associated to an event identified by `context`. +The default implementation assumes a dictionary-like object `state.logging_action`, which holds +the different registered actions. +""" +function logging_action(::Problem, ::Algorithm, state::State, context::Symbol) + return get(state.logging_actions, context, nothing) +end + +@doc """ + loggroup(algorithm::Algorithm) -> Symbol + loggroup(::Type{<:Algorithm}) -> Symbol + +Generate a group id to attach to all log records for a given algorithm. +""" loggroup + +loggroup(algorithm::Algorithm) = loggroup(typeof(algorithm)) +loggroup(Alg::Type{<:Algorithm}) = Base.nameof(Alg) + +# Sources +# ------- +""" + LoggingAction + +Abstract supertype for defining an action that generates a log record. + +## Methods +Any concrete subtype should at least implement the following method: +- [`logdata!(action, problem, algorithm, state)`](@ref logdata!) : generate the data for the log record. + +Addionally, the following methods can be specialized to alter the default behavior: +- [`loglevel(action) = Logging.Info`](@ref loglevel) : specify the logging level of the generated record. +- [`logid(action) = objectid(action)`](@ref logid) : specify a unique identifier to associate with the record. +""" +abstract type LoggingAction end + +logdata!(::LoggingAction, ::Problem, ::Algorithm, ::State) = missing +loglevel(::LoggingAction) = Logging.Info +logid(action::LoggingAction) = objectid(action) + +struct LogCallback{F} <: LoggingAction + f::F +end + +logdata!(action::LogCallback, problem, algorithm, state) = + action.f(problem, algorithm, state) + +struct LogGroup{A <: LoggingAction} <: LoggingAction + actions::Vector{A} +end + +loglevel(alg::LogGroup) = maximum(loglevel, alg.actions) + +logdata!(action::LogGroup, problem, algorithm, state) = map(action.actions) do action + return logdata!(action, problem, algorithm, state) +end + +struct LogLvl{F, A <: LoggingAction} <: LoggingAction + action::A + lvl::LogLevel +end + +loglevel(alg::LogLvl) = alg.lvl + +struct LogIf{F, A <: LoggingAction} <: LoggingAction + predicate::F + action::A +end + +# first cheap check through the level +loglevel(alg::LogIf) = loglevel(alg.action) + +# second check through the predicate +logdata!(action::LogIf, problem::Problem, algorithm::Algorithm, state::State) = + action.predicate(problem, algorithm, state) ? logdata!(action.action, problem, algorithm, state) : nothing + +# Sinks +# ----- +struct StringFormat{F <: PrintF.Format} + format::F +end +function (formatter::StringFormat)(io::IO, lvl, msg, _module, group, id, file = nothing, line = nothing; indent::Integer = 0, kwargs...) + iob = IOBuffer() + return ioc = IOContext(iob, io) + +end + +struct FormatterGroup{K, V} + rules::Dict{K, V} +end + +function (formatter::AlgorithmFormatter)(io::IO, log) + rule = get(formatter.rules, log.id, nothing) + isnothing(rule) ? println(io, log) : + rule(io, log.level, log.message, log._module, log.group, log.id, log.file, log.line; log.kwargs...) + return nothing +end From e11636f48fc8394b67bfac9cdb8a49b9f878c30d Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Tue, 4 Nov 2025 18:07:16 -0500 Subject: [PATCH 04/23] some actual progress --- Project.toml | 4 + src/AlgorithmsInterface.jl | 2 + src/logging.jl | 193 +++++++++++++++++++------------------ 3 files changed, 107 insertions(+), 92 deletions(-) diff --git a/Project.toml b/Project.toml index 6cf9f86..f2bce02 100644 --- a/Project.toml +++ b/Project.toml @@ -5,11 +5,15 @@ version = "0.1.0" [deps] Dates = "ade2ca70-3891-5945-98fb-dc099432e06a" +Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" +ScopedValues = "7e506255-f358-4e82-b7e4-beb19740aa63" [compat] Aqua = "0.8" Dates = "1.10" +Printf = "1.11.0" SafeTestsets = "0.1" +ScopedValues = "1.5.0" Test = "1.10" julia = "1.10" diff --git a/src/AlgorithmsInterface.jl b/src/AlgorithmsInterface.jl index 8467abf..f3b32a3 100644 --- a/src/AlgorithmsInterface.jl +++ b/src/AlgorithmsInterface.jl @@ -9,6 +9,8 @@ module AlgorithmsInterface using Dates: Millisecond, Nanosecond, Period, canonicalize, value +using Printf +using ScopedValues include("interface/algorithm.jl") include("interface/problem.jl") diff --git a/src/logging.jl b/src/logging.jl index 9429349..344a9d1 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -1,127 +1,136 @@ -""" - log!(problem::Problem, algorithm::Algorithm, state::State; context::Symbol) -> nothing - -Generate a log record for the given `(problem, algorithm, state)`, using the logging action associated to `context`. -By default, the following events trigger a logging action with the given `context`: - -| context | event | -| --------- | ------------------------------------- | -| :Start | The solver has been initialized. | -| :PreStep | The solver is about to take a step. | -| :PostStep | The solver has taken a step. | -| :Stop | The solver has finished. | - -Specific algorithms can associate other events with other contexts. - -See also [`register_action!`](@ref) to associate custom actions with these contexts. -""" -function log!(problem::Problem, algorithm::Algorithm, state::State; context)::Nothing - action = @something(logging_action(problem, algorithm, state, context), return nothing) - # TODO: filter out `nothing` logdata - @logmsg( - loglevel(action), logdata!(action, problem, algorithm, state), - _id = logid(action), _group = loggroup(algorithm) - ) - return nothing -end - -""" - logging_action(problem::Problem, algorithm::Algorithm, state::State, context::Symbol) - -> Union{Nothing,LoggingAction} - -Obtain the registered logging action associated to an event identified by `context`. -The default implementation assumes a dictionary-like object `state.logging_action`, which holds -the different registered actions. -""" -function logging_action(::Problem, ::Algorithm, state::State, context::Symbol) - return get(state.logging_actions, context, nothing) -end - -@doc """ - loggroup(algorithm::Algorithm) -> Symbol - loggroup(::Type{<:Algorithm}) -> Symbol - -Generate a group id to attach to all log records for a given algorithm. -""" loggroup - -loggroup(algorithm::Algorithm) = loggroup(typeof(algorithm)) -loggroup(Alg::Type{<:Algorithm}) = Base.nameof(Alg) - -# Sources -# ------- +# LoggingAction interface +# ----------------------- """ LoggingAction Abstract supertype for defining an action that generates a log record. ## Methods -Any concrete subtype should at least implement the following method: -- [`logdata!(action, problem, algorithm, state)`](@ref logdata!) : generate the data for the log record. +Any concrete subtype should at least implement the following method to handle the logging event: -Addionally, the following methods can be specialized to alter the default behavior: -- [`loglevel(action) = Logging.Info`](@ref loglevel) : specify the logging level of the generated record. -- [`logid(action) = objectid(action)`](@ref logid) : specify a unique identifier to associate with the record. +- [`handle_message!(action, problem, algorithm, state, args...; kwargs...)`](@ref handle_message!) """ abstract type LoggingAction end -logdata!(::LoggingAction, ::Problem, ::Algorithm, ::State) = missing -loglevel(::LoggingAction) = Logging.Info -logid(action::LoggingAction) = objectid(action) +@doc """ + handle_message!(action::LoggingAction, problem::Problem, algorithm::Algorithm, state::State; kwargs...) -struct LogCallback{F} <: LoggingAction - f::F -end +Entry-point for defining an implementation of how to handle a logging event for a given [`LoggingAction`](@ref). +""" handle_message!(::LoggingAction, ::Algorithm, ::Problem, ::State; kwargs...) -logdata!(action::LogCallback, problem, algorithm, state) = - action.f(problem, algorithm, state) +# Concrete LoggingActions +# ----------------------- +""" + LogGroup(actions::Vector{<:LoggingAction}) +Concrete [`LoggingAction`](@ref) that can be used to sequentially perform each of the `actions`. +""" struct LogGroup{A <: LoggingAction} <: LoggingAction actions::Vector{A} end -loglevel(alg::LogGroup) = maximum(loglevel, alg.actions) - -logdata!(action::LogGroup, problem, algorithm, state) = map(action.actions) do action - return logdata!(action, problem, algorithm, state) +function handle_message!( + action::LogGroup, problem::Problem, algorithm::Algorithm, state::State; kwargs... + ) + for child in action.actions + handle_message!(child, algorithm, problem, state; kwargs...) + end + return nothing end -struct LogLvl{F, A <: LoggingAction} <: LoggingAction - action::A - lvl::LogLevel +""" + CallbackAction(callback) + +Concrete [`LoggingAction`](@ref) that handles a logging event through an arbitrary callback function. +The callback function must have the following signature: +```julia +callback(algorithm, problem, state; kwargs...) = ... +``` +Here `args...` and `kwargs...` are optional and can be filled out with context-specific information. +""" +struct CallbackAction{F} <: LoggingAction + callback::F end -loglevel(alg::LogLvl) = alg.lvl +function handle_message!( + action::CallbackAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... + ) + action.callback(algorithm, problem, state; kwargs...) + return nothing +end -struct LogIf{F, A <: LoggingAction} <: LoggingAction +struct IfAction{F, A <: LoggingAction} <: LoggingAction predicate::F action::A end -# first cheap check through the level -loglevel(alg::LogIf) = loglevel(alg.action) +function handle_message!( + action::IfAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... + ) + return action.predicate(problem, algorithm, state; kwargs...) ? + handle_message(action.action, problem, algorithm, state; kwargs...) : + nothing +end -# second check through the predicate -logdata!(action::LogIf, problem::Problem, algorithm::Algorithm, state::State) = - action.predicate(problem, algorithm, state) ? logdata!(action.action, problem, algorithm, state) : nothing +# Algorithm Logger +# ---------------- +""" + AlgorithmLogger(context => action, ...) -# Sinks -# ----- -struct StringFormat{F <: PrintF.Format} - format::F -end -function (formatter::StringFormat)(io::IO, lvl, msg, _module, group, id, file = nothing, line = nothing; indent::Integer = 0, kwargs...) - iob = IOBuffer() - return ioc = IOContext(iob, io) +Logging transformer that handles the logic of dispatching logging events to logging actions. +By default, the following events trigger a logging action with the given `context`: +| context | event | +| --------- | ----------------------------------- | +| :Start | The solver will start. | +| :Init | The solver has been initialized. | +| :PreStep | The solver is about to take a step. | +| :PostStep | The solver has taken a step. | +| :Stop | The solver has finished. | + +Specific algorithms can associate other events with other contexts. + +See also the scoped value [`AlgorithmsInterface.algorithm_logger`](@ref). +""" +struct AlgorithmLogger + actions::Dict{Symbol, LogAction} end +AlgorithmLogger(args...) = AlgorithmLogger(Dict{Symbol, LogAction}(args...)) -struct FormatterGroup{K, V} - rules::Dict{K, V} +""" + const LOGGING_ENABLED = Ref(true) + +Global toggle for enabling and disabling all logging features. +""" +const LOGGING_ENABLED = Ref(true) + +""" + const algorithm_logger = ScopedValue(AlgorithmLogger()) + +Scoped value for handling the logging events of arbitrary algorithms. +""" +const ALGORITHM_LOGGER = ScopedValue(AlgorithmLogger()) + +# @inline here to enable the cheap global check +@inline function log!(problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) + if LOGGING_ENABLED[] + logger::AlgorithmLogger = ALGORITHM_LOGGER[] + handle_message(logger, problem, algorithm, state, context; kwargs...) + end + return nothing end -function (formatter::AlgorithmFormatter)(io::IO, log) - rule = get(formatter.rules, log.id, nothing) - isnothing(rule) ? println(io, log) : - rule(io, log.level, log.message, log._module, log.group, log.id, log.file, log.line; log.kwargs...) +# @noinline to keep the algorithm function bodies small +@noinline function handle_message( + alglogger::AlgorithmLogger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; + kwargs... + ) + action::LoggingAction = @something(get(alglogger.actions, context, nothing), return nothing) + try + handle_message!(action, problem, algorithm, state, args...; kwargs...) + catch err + bt = catch_backtrace() + @error "Error during the handling of a logging action" action exception = (err, bt) + end return nothing end From 0b7ea5d3a2eed483ce4bd53b7b7a0ea956053385 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 12:58:34 -0500 Subject: [PATCH 05/23] small fixes --- src/interface/interface.jl | 8 ++++---- src/logging.jl | 4 ++-- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/src/interface/interface.jl b/src/interface/interface.jl index 866b3a2..118229e 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -44,14 +44,14 @@ All keyword arguments are passed to the [`initialize_state!`](@ref)`(problem, al """ function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) initialize_state!(problem, algorithm, state; kwargs...) - log!(problem, algorithm, state; context = :Start) + log!(problem, algorithm, state, :Start) while !is_finished!(problem, algorithm, state) - log!(problem, algorithm, state; context = :PreStep) + log!(problem, algorithm, state, :PreStep) increment!(state) step!(problem, algorithm, state) - log!(problem, algorithm, state; context = :PostStep) + log!(problem, algorithm, state, :PostStep) end - log!(problem, algorithm, state; context = :Stop) + log!(problem, algorithm, state, :Stop) return state end diff --git a/src/logging.jl b/src/logging.jl index 344a9d1..f2526d9 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -93,9 +93,9 @@ Specific algorithms can associate other events with other contexts. See also the scoped value [`AlgorithmsInterface.algorithm_logger`](@ref). """ struct AlgorithmLogger - actions::Dict{Symbol, LogAction} + actions::Dict{Symbol, LoggingAction} end -AlgorithmLogger(args...) = AlgorithmLogger(Dict{Symbol, LogAction}(args...)) +AlgorithmLogger(args...) = AlgorithmLogger(Dict{Symbol, LoggingAction}(args...)) """ const LOGGING_ENABLED = Ref(true) From ad95017297a7a499ebffea6ac8a8b6b739fc50d2 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 13:05:41 -0500 Subject: [PATCH 06/23] fix Printf compat --- Project.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Project.toml b/Project.toml index f2bce02..2c4fb10 100644 --- a/Project.toml +++ b/Project.toml @@ -11,7 +11,7 @@ ScopedValues = "7e506255-f358-4e82-b7e4-beb19740aa63" [compat] Aqua = "0.8" Dates = "1.10" -Printf = "1.11.0" +Printf = "1.10" SafeTestsets = "0.1" ScopedValues = "1.5.0" Test = "1.10" From 195a9c7ffa2aaf20642a66dc9cb647383288dc59 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 13:09:36 -0500 Subject: [PATCH 07/23] minor optimizations --- src/interface/interface.jl | 9 +++++---- src/logging.jl | 1 + 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/src/interface/interface.jl b/src/interface/interface.jl index 118229e..5a25a52 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -43,15 +43,16 @@ The state is modified in-place. All keyword arguments are passed to the [`initialize_state!`](@ref)`(problem, algorithm, state)` function. """ function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) + logger = ALGORITHM_LOGGER[] initialize_state!(problem, algorithm, state; kwargs...) - log!(problem, algorithm, state, :Start) + LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :Start) while !is_finished!(problem, algorithm, state) - log!(problem, algorithm, state, :PreStep) + LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :PreStep) increment!(state) step!(problem, algorithm, state) - log!(problem, algorithm, state, :PostStep) + LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :PostStep) end - log!(problem, algorithm, state, :Stop) + LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :Stop) return state end diff --git a/src/logging.jl b/src/logging.jl index f2526d9..885d8af 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -125,6 +125,7 @@ end alglogger::AlgorithmLogger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs... ) + isempty(alglogger.actions) && return nothing action::LoggingAction = @something(get(alglogger.actions, context, nothing), return nothing) try handle_message!(action, problem, algorithm, state, args...; kwargs...) From 2e9d3df367e27e3b90320032032aa036939bb6fa Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 13:13:17 -0500 Subject: [PATCH 08/23] one more optimization attempt --- src/interface/interface.jl | 10 +++++----- src/logging.jl | 7 +++++++ 2 files changed, 12 insertions(+), 5 deletions(-) diff --git a/src/interface/interface.jl b/src/interface/interface.jl index 5a25a52..72458cf 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -43,16 +43,16 @@ The state is modified in-place. All keyword arguments are passed to the [`initialize_state!`](@ref)`(problem, algorithm, state)` function. """ function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) - logger = ALGORITHM_LOGGER[] + logger = algorithm_logger() initialize_state!(problem, algorithm, state; kwargs...) - LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :Start) + isnothing(logger) || handle_message(logger, problem, algorithm, state, :Start) while !is_finished!(problem, algorithm, state) - LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :PreStep) + isnothing(logger) || handle_message(logger, problem, algorithm, state, :PreStep) increment!(state) step!(problem, algorithm, state) - LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :PostStep) + isnothing(logger) || handle_message(logger, problem, algorithm, state, :PostStep) end - LOGGING_ENABLED[] && handle_message(logger, problem, algorithm, state, :Stop) + isnothing(logger) || handle_message(logger, problem, algorithm, state, :Stop) return state end diff --git a/src/logging.jl b/src/logging.jl index 885d8af..7109a69 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -111,6 +111,13 @@ Scoped value for handling the logging events of arbitrary algorithms. """ const ALGORITHM_LOGGER = ScopedValue(AlgorithmLogger()) +function algorithm_logger() + LOGGING_ENABLED[] || return nothing + logger = ALGORITHM_LOGGER[] + isempty(logger.actions) && return nothing + return logger +end + # @inline here to enable the cheap global check @inline function log!(problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) if LOGGING_ENABLED[] From b9c9b263001dd7a85b4c8aa9eda93e0e05269701 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 17:59:01 -0500 Subject: [PATCH 09/23] various improvements and rework interface.md --- docs/src/interface.md | 159 ++++++++++++++++++++++++++++++++----- src/interface/interface.jl | 23 +++++- src/logging.jl | 67 +++++++++++----- 3 files changed, 203 insertions(+), 46 deletions(-) diff --git a/docs/src/interface.md b/docs/src/interface.md index c6bb211..83ce356 100644 --- a/docs/src/interface.md +++ b/docs/src/interface.md @@ -1,28 +1,139 @@ -# The algorithm interface +# [The algorithm interface](@id sec_interface) -## General design ideas +This section starts a single, cohesive story that will weave through all documentation pages. +We will incrementally build an iterative algorithm, enrich it with stopping criteria, and +finally refine how it records (logs) its progress. Instead of presenting the API in the +abstract, we anchor every concept in one concrete, tiny example you can copy & adapt. -The interface this package provides is based on three ingredients of running an algorithm -consists of: +Why an “interface” for algorithms? Iterative numerical methods nearly always share the +same moving pieces: -* a [`Problem`](@ref) that is to be solved and contains all information that is algorithm independent. - This is _static information_ in the sense that it does not change during the runtime of the algorithm. -* an [`Algorithm`](@ref) that includes all of the _settings_ and _parameters_ that an algorithm. - this is also information that is _static_. -* a [`State`](@ref) that contains all remaining data, especially data that might vary during the iteration, - temporary caches, for example the current iteration the algorithm run is in and the current iterate, respectively. +* immutable input (the mathematical problem you are solving), +* immutable configuration (parameters and knobs of the chosen algorithm), and +* mutable working data (current iterate, caches, diagnostics) that evolves as you step. -The combination of the static information should be enough to initialize the varying data. +Bundling these together loosely—without forcing one giant monolithic type—makes it easier to: -This general scheme is a guiding principle of the package, splitting information into _static_ -or _configuration_ types or data that allows to [`initialize_state`](@ref) a corresponding _variable_ data type. +* reason about what is allowed to change and what must remain fixed, +* write generic tooling (e.g. stopping logic, logging, benchmarking) that applies across many algorithms, +* test algorithms in isolation by constructing minimal `Problem`/`Algorithm` pairs, and +* extend behavior (add new stopping criteria, new logging events) without rewriting core loops. -The order of arguments is given by two ideas +The interface in this package formalizes those roles with three abstract types: +* [`Problem`](@ref): immutable, algorithm‑agnostic input data. +* [`Algorithm`](@ref): immutable configuration and parameters deciding how to iterate. +* [`State`](@ref): mutable data that evolves (current iterate, caches, counters, diagnostics). +It provides a framework for decomposing iterative methods into small, composable parts: +concrete `Problem`/`Algorithm`/`State` types have to implement a minimal set of core functionality, +and this package helps to stitch everything together and provide additional helper functionality such as stopping criteria and logging functionality. -1. for non-mutating functions the order should be from the most fixed data to the most variable one. - For example the three types just mentioned would be ordered like `f(problem, algorithm, state)` -2. For mutating functions the variable that is mutated comes first, for the remainder the guiding principle from 1 continues. - The main case here is `f!(state, problem, algorithm)`. +## [Concrete example: Heron's method](@id sec_heron) + +To make everything tangible, we will work through a concrete example to illustrate the library's goals and concepts. +Our running example is Heron's / Babylonian method for estimating $\sqrt{S}$. +(see also the concise background on Wikipedia: [Babylonian method (Heron's method)](https://en.wikipedia.org/wiki/Methods_of_computing_square_roots#Babylonian_method)): +Starting from an initial guess $x_0$, we may converge to the solution by iterating: + +$$x_{k+1} = \frac{1}{2}\left(x_k + \frac{S}{x_k}\right)$$ + +We therefore suggest the following concrete implementations of the abstract types provided by this package: +They are illustrative; various performance and generality questions will be left unaddressed to keep this example simple. + +### Algorithm types + +```@example Heron +using AlgorithmsInterface + +struct SqrtProblem <: Problem + S::Float64 # number whose square root we seek +end + +struct HeronAlgorithm <: Algorithm + stopping_criterion # will be plugged in later (any StoppingCriterion) +end + +mutable struct HeronState <: State + iterate::Float64 # current iterate + iteration::Int # current iteration count + stopping_criterion_state # will be plugged in later (any StoppingCriterionState) +end +``` + +### Initialization + +In order to start implementing the core parts of our algorithm, we start at the very beginning. +There are two main entry points provided by the interface: + +- [`initialize_state`](@ref) constructs an entirely new state for the algorithm +- [`initialize_state!`](@ref) (in-place) reset of an existing state. + +An example implementation might look like: + +```@example Heron +function AlgorithmsInterface.initialize_state(problem::SqrtProblem, algorithm::HeronAlgorithm; kwargs...) + x0 = rand() # random initial guess + stopping_criterion_state = initialize_state(problem, algorithm, algorithm.stopping_criterion) + return HeronState(x0, 0, stopping_criterion_state) +end + +function AlgorithmsInterface.initialize_state!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState; kwargs...) + # reset the state for the algorithm + state.iterate = rand() + state.iteration = 0 + + # reset the state for the stopping criterion + state = AlgorithmsInterface.initialize_state!( + problem, algorithm, algorithm.stopping_criterion, state.stopping_criterion_state + ) + return state +end +``` + +### Iteration steps + +Algorithms define a mutable step via [`step!`](@ref). For Heron's method: + +```@example Heron +function AlgorithmsInterface.step!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState) + S = problem.S + x = state.iterate + state.iterate = 0.5 * (x + S / x) + return state +end +``` + +Note that we are only focussing on the actual algorithm, and *not* incrementing the iteration counter. +These kinds of bookkeeping should be handled by the [`increment!(state)`](@ref) function, which will by default already increment the iteration counter. +The following generic functionality is therefore enough for our purposes, and does *not* need to be defined. +Nevertheless, if additional bookkeeping would be desired, this can be achieved by overloading that function: + +```julia +function AlgorithmsInterface.increment!(state::State) + state.iteration += 1 + return state +end +``` + +### Running the algorithm + +With these definitions in place you can already run (assuming you also choose a stopping criterion – added in the next section): + +```@example Heron +function heron_sqrt(x; maxiter = 10) + prob = SqrtProblem(x) + alg = HeronAlgorithm(StopAfterIteration(maxiter)) + state = solve(prob, alg) # allocates & runs + return state.iterate +end + +println("Approximate sqrt: ", heron_sqrt(16.0)) +``` + +We will refine this example with better halting logic and logging shortly. + +## Reference: Core interface types & functions + +Below are the automatic API docs for the core interface pieces. Read them after grasping the example above – the intent should now be clearer. ```@autodocs Modules = [AlgorithmsInterface] @@ -31,7 +142,7 @@ Order = [:type, :function] Private = true ``` -## Algorithm +### Algorithm ```@autodocs Modules = [AlgorithmsInterface] @@ -40,7 +151,7 @@ Order = [:type, :function] Private = true ``` -## Problem +### Problem ```@autodocs Modules = [AlgorithmsInterface] @@ -49,11 +160,15 @@ Order = [:type, :function] Private = true ``` -## State +### State ```@autodocs Modules = [AlgorithmsInterface] Pages = ["interface/state.jl"] Order = [:type, :function] Private = true -``` \ No newline at end of file +``` + +### Next: Stopping criteria + +Proceed to the stopping criteria section to add robust halting logic (iteration caps, time limits, tolerance on successive iterates, and combinations) to this square‑root example. diff --git a/src/interface/interface.jl b/src/interface/interface.jl index 72458cf..6223fcc 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -43,16 +43,31 @@ The state is modified in-place. All keyword arguments are passed to the [`initialize_state!`](@ref)`(problem, algorithm, state)` function. """ function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) + # obtain logger once to minimize overhead from accessing ScopedValue + # additionally handle logging initialization to enable stateful LoggingAction logger = algorithm_logger() + # initialize_logger(logger, problem, algorithm, state) + + # initialize the state and emit message initialize_state!(problem, algorithm, state; kwargs...) - isnothing(logger) || handle_message(logger, problem, algorithm, state, :Start) + emit_message(logger, problem, algorithm, state, :Start) + + # main body of the algorithm while !is_finished!(problem, algorithm, state) - isnothing(logger) || handle_message(logger, problem, algorithm, state, :PreStep) + # logging event between convergence check and algorithm step + emit_message(logger, problem, algorithm, state, :PreStep) + + # algorithm step increment!(state) step!(problem, algorithm, state) - isnothing(logger) || handle_message(logger, problem, algorithm, state, :PostStep) + + # logging event between algorithm step and convergence check + emit_message(logger, problem, algorithm, state, :PostStep) end - isnothing(logger) || handle_message(logger, problem, algorithm, state, :Stop) + + # emit message about finished state + emit_message(logger, problem, algorithm, state, :Stop) + return state end diff --git a/src/logging.jl b/src/logging.jl index 7109a69..1d8f1c2 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -46,7 +46,7 @@ The callback function must have the following signature: ```julia callback(algorithm, problem, state; kwargs...) = ... ``` -Here `args...` and `kwargs...` are optional and can be filled out with context-specific information. +Here `kwargs...` are optional and can be filled out with context-specific information. """ struct CallbackAction{F} <: LoggingAction callback::F @@ -59,6 +59,16 @@ function handle_message!( return nothing end +""" + IfAction(predicate, action) + +Concrete [`LoggingAction`](@ref) that wraps another action and hides it behind a clause, only +emitting logging events whenever the `predicate` evaluates to true. The `predicate` must have +the signature: +```julia +predicate(algorithm, problem, state; kwargs...)::Bool +``` +""" struct IfAction{F, A <: LoggingAction} <: LoggingAction predicate::F action::A @@ -97,18 +107,34 @@ struct AlgorithmLogger end AlgorithmLogger(args...) = AlgorithmLogger(Dict{Symbol, LoggingAction}(args...)) -""" - const LOGGING_ENABLED = Ref(true) -Global toggle for enabling and disabling all logging features. -""" +@doc """ + get_global_logging_state() + set_global_logging_state!(state::Bool) -> previous_state + +Retrieve or set the value to globally enable or disable the handling of logging events. +""" get_global_logging_state, set_global_logging_state! + const LOGGING_ENABLED = Ref(true) -""" - const algorithm_logger = ScopedValue(AlgorithmLogger()) +get_global_logging_state() = LOGGING_ENABLED[] +function set_global_logging_state(state::Bool) + previous = LOGGING_ENABLED[] + LOGGING_ENABLED[] = state + return previous +end + + +@doc """ + algorithm_logger()::Union{AlgorithmLogger, Nothing} + +Retrieve the current logger that is responsible for handling logging events. +The current logger is determined by a `ScopedValue`. +Whenever `nothing` is returned, no logging should happen. + +See also [`set_global_logging_state!`](@ref) for globally toggling whether logging should happen. +""" algorithm_logger -Scoped value for handling the logging events of arbitrary algorithms. -""" const ALGORITHM_LOGGER = ScopedValue(AlgorithmLogger()) function algorithm_logger() @@ -118,21 +144,22 @@ function algorithm_logger() return logger end -# @inline here to enable the cheap global check -@inline function log!(problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) - if LOGGING_ENABLED[] - logger::AlgorithmLogger = ALGORITHM_LOGGER[] - handle_message(logger, problem, algorithm, state, context; kwargs...) - end - return nothing -end +""" + emit_message(problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) -> nothing + emit_message(algorithm_logger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) -> nothing -# @noinline to keep the algorithm function bodies small -@noinline function handle_message( +Use the current or the provided algorithm logger to handle the logging event of the given `context`. +The [`AlgorithmLogger`](@ref) is responsible for dispatching the correct events to the correct [`LoggingAction`](@ref)s. +""" +emit_message(problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) = + emit_message(algorithm_logger(), problem, algorithm, state, context; kwargs...) +emit_message(::Nothing, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) = + nothing +function emit_message( alglogger::AlgorithmLogger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs... ) - isempty(alglogger.actions) && return nothing + @noinline; @nospecialize action::LoggingAction = @something(get(alglogger.actions, context, nothing), return nothing) try handle_message!(action, problem, algorithm, state, args...; kwargs...) From e293ccd7ebadf10ce916d2da8ec3c56188f40ab0 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 18:01:31 -0500 Subject: [PATCH 10/23] small docstring typos --- src/interface/interface.jl | 2 +- src/interface/state.jl | 4 ++-- src/stopping_criterion.jl | 2 +- 3 files changed, 4 insertions(+), 4 deletions(-) diff --git a/src/interface/interface.jl b/src/interface/interface.jl index 6223fcc..8640795 100644 --- a/src/interface/interface.jl +++ b/src/interface/interface.jl @@ -1,6 +1,6 @@ _doc_init_state = """ state = initialize_state(problem::Problem, algorithm::Algorithm; kwargs...) - state = initialize_state!(state::State, problem::Problem, algorithm::Algorithm; kwargs...) + state = initialize_state!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) Initialize a [`State`](@ref) based on a [`Problem`](@ref) and an [`Algorithm`](@ref). The `kwargs...` should allow to initialize for example the initial point. diff --git a/src/interface/state.jl b/src/interface/state.jl index 1cab6f3..a0b3601 100644 --- a/src/interface/state.jl +++ b/src/interface/state.jl @@ -14,13 +14,13 @@ and provide corresponding `getproperty` and `setproperty!` methods. * `iteration` – the current iteration step ``k`` that is is currently performed or was last performed * `stopping_criterion_state` – a [`StoppingCriterionState`](@ref) that indicates whether an [`Algorithm`](@ref) will stop after this iteration or has stopped. -* `iterate` the current iterate ``x^{(k)}```. +* `iterate` the current iterate ``x^{(k)}``. ## Methods The following methods should be implemented for a state -* [`increment!](@ref)`(state)` +* [`increment!`](@ref)(state) """ abstract type State end diff --git a/src/stopping_criterion.jl b/src/stopping_criterion.jl index 2470fdf..934c85b 100644 --- a/src/stopping_criterion.jl +++ b/src/stopping_criterion.jl @@ -237,7 +237,7 @@ Base.:|(s1::StopWhenAny, s2::StopWhenAny) = StopWhenAny(s1.criteria..., s2.crite A [`StoppingCriterionState`](@ref) that groups multiple [`StoppingCriterionState`](@ref)s internally as a tuple. -This is for example used in combination with [`StopWhenAny`](@ref) and [`StopWhenAny`](@ref) +This is for example used in combination with [`StopWhenAny`](@ref) and [`StopWhenAll`](@ref) # Constructor GroupStoppingCriterionState(c::Vector{N,StoppingCriterionState} where N) From 0eb141a9b4c52bf843906bfc0c70b81704499551 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 20:47:08 -0500 Subject: [PATCH 11/23] stopping criterion docs and small fixes --- docs/src/stopping_criterion.md | 273 ++++++++++++++++++++++++++++++++- src/stopping_criterion.jl | 23 ++- 2 files changed, 282 insertions(+), 14 deletions(-) diff --git a/docs/src/stopping_criterion.md b/docs/src/stopping_criterion.md index 6f5917c..c639637 100644 --- a/docs/src/stopping_criterion.md +++ b/docs/src/stopping_criterion.md @@ -1,8 +1,277 @@ -# Stopping criterion +# Stopping criteria + +Continuing the square‑root story from the [Interface](@ref sec_interface) page, we now decide **when** the iteration should halt. +A stopping criterion encapsulates halting logic separately from the algorithm update rule. + +## Why separate stopping logic? + +Decoupling halting from stepping lets us: + +* Reuse generic stopping (iteration caps, time limits) across algorithms. +* Compose multiple conditions (stop after 1 second OR 100 iterations, etc.). +* Query convergence indication vs. mere forced termination. +* Store structured reasons and state (e.g. at which iteration a threshold was met). + + +## Built-in criteria: Heron's method + +The package ships several concrete [`StoppingCriterion`](@ref)s: + +* [`StopAfterIteration`](@ref): stop after a maximum number of iterations. +* [`StopAfter`](@ref): stop after a wall‑clock time `Period` (e.g. `Second(2)`, `Minute(1)`). +* Combinations [`StopWhenAll`](@ref) (logical AND) and [`StopWhenAny`](@ref) (logical OR) built via `&` and `|` operators. + +Each criterion has an associated [`StoppingCriterionState`](@ref) storing dynamic data (iteration when met, elapsed time, etc.). + +Recall our [example implementation](@ref sec_heron) for Heron's method, where we we added a `stopping_criterion` to the `Algorithm`, as well as a `stopping_criterion_state` to the `State`. + +```@example Heron +using AlgorithmsInterface + +struct SqrtProblem <: Problem + S::Float64 # number whose square root we seek +end + +struct HeronAlgorithm <: Algorithm + stopping_criterion # any StoppingCriterion +end + +mutable struct HeronState <: State + iterate::Float64 # current iterate + iteration::Int # current iteration count + stopping_criterion_state # any StoppingCriterionState +end +``` + +Here, we delve a bit deeper into the core components of what made our algorithm stop, even though we had to add very little additional functionality. + +### Initialization + +The first core component to enable working with stopping criteria is to extend the initialization step to include initializing a [`StoppingCriterionState`](@ref) as well. +This can conveniently be done through the same initialization functions we used for initializing the state: + +- [`initialize_state`](@ref) constructs an entirely new stopping state for the algorithm +- [`initialize_state!`](@ref) (in-place) reset of an existing stopping state. + +```@example Heron +function AlgorithmsInterface.initialize_state(problem::SqrtProblem, algorithm::HeronAlgorithm; kwargs...) + x0 = rand() # random initial guess + stopping_criterion_state = initialize_state(problem, algorithm, algorithm.stopping_criterion) + return HeronState(x0, 0, stopping_criterion_state) +end + +function AlgorithmsInterface.initialize_state!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState; kwargs...) + # reset the state for the algorithm + state.iterate = rand() + state.iteration = 0 + + # reset the state for the stopping criterion + state = AlgorithmsInterface.initialize_state!( + problem, algorithm, algorithm.stopping_criterion, state.stopping_criterion_state + ) + return state +end +``` + +### Iteration + +During the iteration procedure, as set out by our design principles, we do not have to modify any of the code, and the stopping criteria do not show up: + +```@example Heron +function AlgorithmsInterface.step!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState) + S = problem.S + x = state.iterate + state.iterate = 0.5 * (x + S / x) + return state +end +``` + +What is really going on is that behind the scenes, the loop of the iterative solver expands to code that is equivalent to: + +```julia +while !is_finished!(problem, algorithm, state) + increment!(state) + step!(problem, algorithm, state) +end +``` + +In other words, all of the logic is handled by the [`is_finished!`](@ref) function. +The generic stopping criteria provided by this package have default implementations for this function that work out-of-the-box. +This is partially because we used conventional names for the fields in the structs. +There, `Algorithm` assumes the existence of `stopping_criterion`, while `State` assumes `iterate` and `iteration` and `stopping_criterion_state` to exist. + +### Running the algorithm + +We can again combine everything into a single function, but now make the stopping criterion accessible: + +```@example Heron +function heron_sqrt(x; stopping_criterion) + prob = SqrtProblem(x) + alg = HeronAlgorithm(stopping_criterion) + state = solve(prob, alg) # allocates & runs + return state.iterate, state.iteration +end + +heron_sqrt(2; stopping_criterion = StopAfterIteration(10)) +``` + +With this function, we are now ready to explore different ways of telling the algorithm to stop. +For example, using the basic criteria provided by this package, we can alternatively do: + +```@example Heron +using Dates +criterion = StopAfter(Millisecond(50)) +heron_sqrt(2; stopping_criterion = criterion) +``` + +We can tighten the condition by combining criteria. Suppose we want to stop after either 25 iterations or 50 milliseconds, whichever comes first: + +```@example Heron +criterion = StopAfterIteration(25) | StopAfter(Millisecond(50)) # logical OR +heron_sqrt(2; stopping_criterion = criterion) +``` + +Conversely, to demand both a minimum iteration quality condition **and** a cap, use `&` (logical AND). + +```@example Heron +criterion = StopAfterIteration(25) & StopAfter(Millisecond(50)) # logical AND +heron_sqrt(2; stopping_criterion = criterion) +``` + +## Implementing a new criterion + +It is of course possible that we are not satisfied by the stopping criteria that are provided by default. +Suppose we want to stop when successive iterates change by less than `ϵ`, we could achieve this by implementing our own stopping criterion. +In order to do so, we need to define our own structs and implement the required interface. +Again, we split up the data into a _static_ part, the [`StoppingCriterion`](@ref), and a _dynamic_ part, the [`StoppingCriterionState`](@ref). + +```@example Heron +struct StopWhenStable <: StoppingCriterion + tol::Float64 # when do we consider things converged +end + +mutable struct StopWhenStableState <: StoppingCriterionState + previous_iterate::Float64 # previous value to compare to + at_iteration::Int # iteration at which stability was reached + delta::Float64 # difference between the values +end +``` + +Note that our mutable state holds both the `previous_iterate`, which we need to compare to, +as well as the iteration at which the condition was satisfied. +This is not strictly necessary, but can be convenient to have a persistent indication that convergence was reached. + +### Initialization + +In order to support these _stateful_ criteria, again an initialization phase is needed. +This could be implemented as follows: + +```@example Heron +function AlgorithmsInterface.initialize_state(::Problem, ::Algorithm, c::StopWhenStable; kwargs...) + return StopWhenStableState(NaN, -1, NaN) +end + +function AlgorithmsInterface.initialize_state!( + ::Problem, ::Algorithm, stop_when::StopWhenStable, st::StopWhenStableState; + kwargs... +) + st.previous_iterate = NaN + st.at_iteration = -1 + st.delta = NaN + return st +end +``` + +### Checking for convergence + +Then, we need to implement the logic that checks whether an algorithm has finished, which is achieved through [`is_finished`](@ref) and [`is_finished!`](@ref). +Here, the mutating version alters the `stopping_criterion_state`, and should therefore be called exactly once per iteration, while the non-mutating version is simply used to inspect the current status. + +```@example Heron +function AlgorithmsInterface.is_finished!( + ::Problem, ::Algorithm, state::State, c::StopWhenStable, st::StopWhenStableState +) + k = state.iteration + if k == 0 + st.previous_iterate = state.iterate + st.at_iteration = -1 + return false + end + + st.delta = abs(state.iterate - st.previous_iterate) + st.previous_iterate = state.iterate + if st.delta < c.tol + st.at_iteration = k + return true + end + return false +end + +function AlgorithmsInterface.is_finished( + ::Problem, ::Algorithm, state::State, c::StopWhenStable, st::StopWhenStableState +) + k = state.iteration + k == 0 && return false + + Δ = abs(state.iterate - st.previous_iterate) + return Δ < c.tol +end +``` + +### Reason and convergence reporting + +Finally, we need to implement [`get_reason`](@ref) and [`indicates_convergence`](@ref). +These helper functions are required to interact with the [logging system](@ref sec_logging), to distinguish between states that are considered ongoing, stopped and converged, or stopped without convergence. + +```@example Heron +function AlgorithmsInterface.get_reason(c::StopWhenStable, st::StopWhenStableState) + (st.at_iteration >= 0 && st.delta < c.tol) || return nothing + return "The algorithm reached an approximate stable point after $(st.at_iteration) iterations; the change $(st.delta) is less than $(c.tol)." +end + +AlgorithmsInterface.indicates_convergence(c::StopWhenStable, st::StopWhenStableState) = true +``` + +### Convergence in action + +Then we are finally ready to test out our new stopping criterion. + +```@example Heron +criterion = StopWhenStable(1e-8) +heron_sqrt(16.0; stopping_criterion = criterion) +``` + +Note that our work payed off, as we can still compose this stopping criterion with other criteria as well: + +```@example Heron +criterion = StopWhenStable(1e-8) | StopAfterIteration(5) +heron_sqrt(16.0; stopping_criterion = criterion) +``` + +### Summary + +Implementing a criterion usually means defining: + +1. A subtype of [`StoppingCriterion`](@ref). +2. A state subtype of [`StoppingCriterionState`](@ref) capturing dynamic fields. +3. `initialize_state` and `initialize_state!` for setup/reset. +4. `is_finished!` (mutating) and optionally `is_finished` (non‑mutating) variants. +5. `get_reason` (return `nothing` or a string) for user feedback. +6. `indicates_convergence(::YourCriterion)` to mark if meeting it implies convergence. + +You may also implement `Base.summary(io, criterion, criterion_state)` for compact status reports. + +## Reference API + +Below are the auto‑generated docs for all stopping criterion infrastructure. ```@autodocs Modules = [AlgorithmsInterface] Pages = ["stopping_criterion.jl"] Order = [:type, :function] Private = true -``` \ No newline at end of file +``` + +### Next: Logging + +With halting logic done, proceed to the [logging section](@ref sec_logging) to instrument the same example and capture intermediate diagnostics. diff --git a/src/stopping_criterion.jl b/src/stopping_criterion.jl index 934c85b..a6da5d0 100644 --- a/src/stopping_criterion.jl +++ b/src/stopping_criterion.jl @@ -37,7 +37,7 @@ function get_reason end get_reason(stopping_criterion::StoppingCriterion, stopping_criterion_state::StoppingCriterionState) Provide a reason in human readable text as to why a [`StoppingCriterion`](@ref) with [`StoppingCriterionState`](@ref) indicated to stop. -If it does not indicate to stop, this should return an empty string. +If it does not indicate to stop, this should return `nothing`. Providing the iteration at which this indicated to stop in the reason would be preferable. """ @@ -54,8 +54,7 @@ indicates_convergence(stopping_criterion::StoppingCriterion) @doc """ indicates_convergence(stopping_criterion::StoppingCriterion, ::StoppingCriterionState) -Return whether or not a [`StoppingCriterion`](@ref) indicates convergence -when it is in [`StoppingCriterionState`](@ref) +Return whether or not a [`StoppingCriterion`](@ref) indicates convergence when it is in [`StoppingCriterionState`](@ref). By default this checks whether the [`StoppingCriterion`](@ref) has actually stopped. If so it returns whether `stopping_criterion` itself indicates convergence, otherwise it returns `false`, @@ -275,19 +274,19 @@ function initialize_state( ) end function initialize_state!( - stopping_criterion_states::GroupStoppingCriterionState, problem::Problem, algorithm::Algorithm, - stop_when::Union{StopWhenAll, StopWhenAny}; + stop_when::Union{StopWhenAll, StopWhenAny}, + stopping_criterion_states::GroupStoppingCriterionState; kwargs..., ) for (stopping_criterion_state, stopping_criterion) in zip(stopping_criterion_states.criteria_states, stop_when.criteria) initialize_state!( - stopping_criterion_state, problem, algorithm, - stopping_criterion; + stopping_criterion, + stopping_criterion_state; kwargs..., ) end @@ -441,10 +440,10 @@ end initialize_state(::Problem, ::Algorithm, ::StopAfterIteration; kwargs...) = DefaultStoppingCriterionState() function initialize_state!( - stopping_criterion_state::DefaultStoppingCriterionState, ::Problem, ::Algorithm, - ::StopAfterIteration; + ::StopAfterIteration, + stopping_criterion_state::DefaultStoppingCriterionState; kwargs..., ) stopping_criterion_state.at_iteration = -1 @@ -550,10 +549,10 @@ initialize_state(::Problem, ::Algorithm, ::StopAfter; kwargs...) = StopAfterTimePeriodState() function initialize_state!( - stopping_criterion_state::DefaultStoppingCriterionState, ::Problem, ::Algorithm, - ::StopAfter; + ::StopAfter, + stopping_criterion_state::StopAfterTimePeriodState; kwargs..., ) stopping_criterion_state.start = Nanosecond(0) @@ -586,7 +585,7 @@ function is_finished!( stop_after_state.start = Nanosecond(time_ns()) stop_after_state.time = Nanosecond(0) else - stop_after_state.time = Nanosecond(time_ns()) - stopping_criterion_state.start + stop_after_state.time = Nanosecond(time_ns()) - stop_after_state.start if k > 0 && (stop_after_state.time > Nanosecond(stop_after.threshold)) stop_after_state.at_iteration = k return true From 8d5f4528df2c2f1a57a756d3cc8f3cbedae76983 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Thu, 6 Nov 2025 20:48:22 -0500 Subject: [PATCH 12/23] WIP --- docs/make.jl | 4 + docs/src/logging.md | 195 ++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 199 insertions(+) create mode 100644 docs/src/logging.md diff --git a/docs/make.jl b/docs/make.jl index dc79dac..7cf366e 100755 --- a/docs/make.jl +++ b/docs/make.jl @@ -46,10 +46,14 @@ makedocs(; "Home" => "index.md", "Interface" => "interface.md", "Stopping criteria" => "stopping_criterion.md", + "Logging" => "logging.md", "Notation" => "notation.md", "References" => "references.md", ], + expandfirst = ["interface.md", "stopping_criterion.md"], plugins = [bib, links], + warnonly = true + ) deploydocs(; repo = "github.com/JuliaManifolds/AlgorithmsInterface.jl", push_preview = true) #back to main env diff --git a/docs/src/logging.md b/docs/src/logging.md new file mode 100644 index 0000000..7e46625 --- /dev/null +++ b/docs/src/logging.md @@ -0,0 +1,195 @@ +# [Logging](@id sec_logging) + +In the final part of the square‑root story we instrument the Heron iteration with logging. +The logging system answers two questions separately: + +* **What happens when we log?** → a [`LoggingAction`](@ref). +* **When do we log?** → an [`AlgorithmLogger`](@ref) mapping contexts to actions. + +This separation lets users compose rich behaviors (printing, collecting stats, plotting) without modifying algorithm code, and lets algorithm authors emit domain‑specific events. + +## Recap: Default logging contexts + +The generic `solve!` loop in `interface/interface.jl` emits these contexts: + +| Context | Meaning | +|-----------:|------------------------------------------| +| `:Start` | Just before iteration begins | +| `:Init` | After state initialization | +| `:PreStep` | Right before a `step!` | +| `:PostStep`| Right after a `step!` | +| `:Stop` | After halting (stopping criterion met) | + +Algorithms may add their own (e.g. `:Refinement`, `:RejectedStep`) by calling [`handle_message`](@ref) with a custom symbol. + +## Global enable/disable + +```julia +using AlgorithmsInterface: set_global_logging_state!, get_global_logging_state +set_global_logging_state!(false) # silence all logging +previous = set_global_logging_state!(true) # restore +``` + +## Instrumenting the square‑root algorithm + +We start with minimal feedback: iteration number and current estimate. + +```julia +iter_printer = CallbackAction() do alg, prob, st + @printf("Iter %3d x = %.12f\n", st.iteration, st.x) +end + +logger = AlgorithmLogger(:PostStep => iter_printer) + +with(ALGORITHM_LOGGER => logger) do + state = solve(SqrtProblem(42.0), HeronAlgorithm(1.0, StopAfterIteration(8))) + println("Final ≈ sqrt(42): ", state.x) +end +``` + +### Timing the run + +Add actions for start timestamp and per‑step elapsed time: + +```julia +start_time = Ref{Float64}(0.0) + +record_start = CallbackAction() do alg, prob, st + start_time[] = time() +end + +show_elapsed = CallbackAction() do alg, prob, st + dt = time() - start_time[] + @printf("Iter %3d elapsed = %.3fs\n", st.iteration, dt) +end + +logger = AlgorithmLogger( + :Init => record_start, + :PostStep => LogGroup([iter_printer, show_elapsed]), + :Stop => CallbackAction() do alg, prob, st + @printf("Done after %d iterations (total %.3fs)\n", st.iteration, time() - start_time[]) + end, +) +``` + +### Conditional logging (every N steps) + +```julia +every_five = IfAction( + (prob, alg, st; kwargs...) -> st.iteration % 5 == 0, + CallbackAction() do alg, prob, st + println("Checkpoint at iteration ", st.iteration) + end, +) + +logger = AlgorithmLogger(:PostStep => every_five) +``` + +### Capturing history for analysis + +Instead of printing, store iterates in a custom action: + +```julia +struct CaptureHistory <: LoggingAction + xs::Vector{Float64} +end +CaptureHistory() = CaptureHistory(Float64[]) + +function AlgorithmsInterface.handle_message!(act::CaptureHistory, prob::SqrtProblem, alg::HeronAlgorithm, st::HeronState; kwargs...) + push!(act.xs, st.x) + return nothing +end + +history = CaptureHistory() +logger = AlgorithmLogger(:PostStep => history) +with(ALGORITHM_LOGGER => logger) do + solve(SqrtProblem(42.0), HeronAlgorithm(1.0, StopWhenStable(1e-10) & StopAfterIteration(200))) +end +println("Stored ", length(history.xs), " iterates") +``` + +You can later inspect convergence visually (plot `history.xs`). + +### Multiple simultaneous behaviors + +Group actions to avoid multiple context entries: + +```julia +logger = AlgorithmLogger( + :PostStep => LogGroup([iter_printer, history, every_five]), +) +``` + +### Adding custom contexts + +Suppose we augment Heron's method with a fallback if `x` becomes non‑finite. We can log that: + +```julia +fallback_action = CallbackAction() do alg, prob, st; println("Fallback triggered at iteration ", st.iteration); end +logger = AlgorithmLogger(:Fallback => fallback_action, :PostStep => iter_printer) + +function safe_step!(prob::SqrtProblem, alg::HeronAlgorithm, st::HeronState) + isnan(st.x) && begin + handle_message(prob, alg, st, :Fallback) + st.x = alg.initial_guess + end + step!(prob, alg, st) +end +``` + +Just call `handle_message(prob, alg, st, :YourContext)` whenever the event occurs. + +### Robustness: error isolation + +If a `LoggingAction` throws, the system catches and reports the error without aborting the algorithm. Keep actions side‑effect focused and fast; heavy processing can collect data during iteration and post‑process afterwards. + +### Writing a new action type (summary statistics) + +```julia +struct StatsCollector <: LoggingAction + n::Int + sum::Float64 +end +StatsCollector() = StatsCollector(0, 0.0) + +function AlgorithmsInterface.handle_message!(act::StatsCollector, prob::SqrtProblem, alg::HeronAlgorithm, st::HeronState; kwargs...) + act.n += 1 + act.sum += st.x +end + +avg_action = CallbackAction() do alg, prob, st + # could query stats at :Stop using captured object +end +stats = StatsCollector() +logger = AlgorithmLogger(:PostStep => LogGroup([stats, iter_printer])) +``` + +At the end: + +```julia +println("Average iterate value = ", stats.sum / stats.n) +``` + +## Choosing what to store vs. print + +Guidelines: + +* Use printing for immediate feedback (development / CLI runs). +* Store vectors / tables in custom actions for later analysis or plotting. +* Keep actions pure w.r.t. algorithm state (read but do not modify `state`). +* Prefer one `LogGroup` per context over many individual mappings. + +## Reference API + +Auto‑generated documentation for logging infrastructure follows. + +```@autodocs +Modules = [AlgorithmsInterface] +Pages = ["logging.jl"] +Order = [:type, :function] +Private = true +``` + +## Wrap‑up + +You have now seen: defining an algorithm (interface page), controlling halting (stopping criteria), and instrumenting execution (logging). Together these patterns encourage modular, testable iterative algorithm design. From c40765ed37a589615aca6829360438c450ccd7d0 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 08:48:47 -0500 Subject: [PATCH 13/23] collapse docstrings by default --- docs/src/interface.md | 4 ++++ docs/src/logging.md | 4 ++++ docs/src/stopping_criterion.md | 4 ++++ 3 files changed, 12 insertions(+) diff --git a/docs/src/interface.md b/docs/src/interface.md index 83ce356..8c83a6e 100644 --- a/docs/src/interface.md +++ b/docs/src/interface.md @@ -1,3 +1,7 @@ +```@meta +CollapsedDocStrings = true +``` + # [The algorithm interface](@id sec_interface) This section starts a single, cohesive story that will weave through all documentation pages. diff --git a/docs/src/logging.md b/docs/src/logging.md index 7e46625..e02e0a4 100644 --- a/docs/src/logging.md +++ b/docs/src/logging.md @@ -1,3 +1,7 @@ +```@meta +CollapsedDocStrings = true +``` + # [Logging](@id sec_logging) In the final part of the square‑root story we instrument the Heron iteration with logging. diff --git a/docs/src/stopping_criterion.md b/docs/src/stopping_criterion.md index c639637..8d553bb 100644 --- a/docs/src/stopping_criterion.md +++ b/docs/src/stopping_criterion.md @@ -1,3 +1,7 @@ +```@meta +CollapsedDocStrings = true +``` + # Stopping criteria Continuing the square‑root story from the [Interface](@ref sec_interface) page, we now decide **when** the iteration should halt. From 464882c9acd5f3f7202d4e24af471ad5d355859d Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 11:12:29 -0500 Subject: [PATCH 14/23] write logging docs --- docs/src/interface.md | 2 +- docs/src/logging.md | 499 +++++++++++++++++++++++++++++-------- src/AlgorithmsInterface.jl | 2 + src/logging.jl | 35 +-- 4 files changed, 424 insertions(+), 114 deletions(-) diff --git a/docs/src/interface.md b/docs/src/interface.md index 8c83a6e..e8ee7ba 100644 --- a/docs/src/interface.md +++ b/docs/src/interface.md @@ -16,7 +16,7 @@ same moving pieces: * immutable configuration (parameters and knobs of the chosen algorithm), and * mutable working data (current iterate, caches, diagnostics) that evolves as you step. -Bundling these together loosely—without forcing one giant monolithic type—makes it easier to: +Bundling these together loosely without forcing one giant monolithic type makes it easier to: * reason about what is allowed to change and what must remain fixed, * write generic tooling (e.g. stopping logic, logging, benchmarking) that applies across many algorithms, diff --git a/docs/src/logging.md b/docs/src/logging.md index e02e0a4..1113330 100644 --- a/docs/src/logging.md +++ b/docs/src/logging.md @@ -4,184 +4,478 @@ CollapsedDocStrings = true # [Logging](@id sec_logging) -In the final part of the square‑root story we instrument the Heron iteration with logging. -The logging system answers two questions separately: +In the final part of the square‑root story we augment Heron's iteration with logging functionality. +For example, we might be interested in the convergence behavior throughout the iterations, timing information, or storing intermediate values for later analysis. +The logging system is designed to provide full flexibility over this behavior, without polluting the core algorithm implementation. +Additionally, we strive to *pay for what you get*: when no logging is configured, there is minimal overhead. +## Why separate logging from algorithms? + +Decoupling logging from algorithm logic lets us: + +* Add diagnostic output without modifying algorithm code. +* Compose multiple logging behaviors (printing, storing, timing) independently. +* Reuse generic logging actions across different algorithms. +* Disable logging globally with zero runtime cost. +* Instrument algorithms with custom events for domain-specific diagnostics. +* Customize logging behavior *a posteriori*: users can add logging features to existing algorithms without modifying library code. + +The logging system aims to achieve these goals by separating the logging logic into two separate parts. +These parts can be roughly described as *events* and *actions*, where the logging system is responsible for mapping between them. +Concretely, we have: + +* **When do we log?** → an [`AlgorithmLogger`](@ref) mapping events to actions. * **What happens when we log?** → a [`LoggingAction`](@ref). -* **When do we log?** → an [`AlgorithmLogger`](@ref) mapping contexts to actions. -This separation lets users compose rich behaviors (printing, collecting stats, plotting) without modifying algorithm code, and lets algorithm authors emit domain‑specific events. +This separation allows users to compose rich behaviors (printing, collecting statistics, plotting) without modifying algorithm code, and lets algorithm authors emit domain‑specific events. -## Recap: Default logging contexts +## Using the default logging actions -The generic `solve!` loop in `interface/interface.jl` emits these contexts: +Continuing from the [Stopping Criteria](@ref) page, we have our Heron's method implementation ready: -| Context | Meaning | -|-----------:|------------------------------------------| -| `:Start` | Just before iteration begins | -| `:Init` | After state initialization | -| `:PreStep` | Right before a `step!` | -| `:PostStep`| Right after a `step!` | -| `:Stop` | After halting (stopping criterion met) | +```@example Heron +using AlgorithmsInterface +using Printf +using Dates # hide -Algorithms may add their own (e.g. `:Refinement`, `:RejectedStep`) by calling [`handle_message`](@ref) with a custom symbol. +struct SqrtProblem <: Problem + S::Float64 +end -## Global enable/disable +struct HeronAlgorithm <: Algorithm + stopping_criterion +end -```julia -using AlgorithmsInterface: set_global_logging_state!, get_global_logging_state -set_global_logging_state!(false) # silence all logging -previous = set_global_logging_state!(true) # restore +mutable struct HeronState <: State + iterate::Float64 + iteration::Int + stopping_criterion_state +end + +function AlgorithmsInterface.initialize_state(problem::SqrtProblem, algorithm::HeronAlgorithm; kwargs...) + x0 = rand() + stopping_criterion_state = initialize_state(problem, algorithm, algorithm.stopping_criterion) + return HeronState(x0, 0, stopping_criterion_state) +end + +function AlgorithmsInterface.initialize_state!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState; kwargs...) + state.iterate = rand() + state.iteration = 0 + initialize_state!(problem, algorithm, algorithm.stopping_criterion, state.stopping_criterion_state) + return state +end + +function AlgorithmsInterface.step!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState) + S = problem.S + x = state.iterate + state.iterate = 0.5 * (x + S / x) + return state +end + +function heron_sqrt(x; stopping_criterion = StopAfterIteration(10)) + prob = SqrtProblem(x) + alg = HeronAlgorithm(stopping_criterion) + state = solve(prob, alg) # allocates & runs + return state.iterate +end +nothing # hide ``` -## Instrumenting the square‑root algorithm +It is already interesting to note that there are no further modifications necessary to start leveraging the logging system. -We start with minimal feedback: iteration number and current estimate. +### Basic iteration printing -```julia -iter_printer = CallbackAction() do alg, prob, st - @printf("Iter %3d x = %.12f\n", st.iteration, st.x) +Let's start with a very basic example of logging: printing iteration information after each step. +We use [`CallbackAction`](@ref) to wrap a simple function that accesses the state, and prints the `iteration` as well as the `iterate`. + +```@example Heron +using Printf +iter_printer = CallbackAction() do problem, algorithm, state + @printf("Iter %3d: x = %.12f\n", state.iteration, state.iterate) end +nothing # hide +``` -logger = AlgorithmLogger(:PostStep => iter_printer) +To activate this logger, we wrap the section of code that we want to enable logging for, and map the `:PostStep` context to our action. +This is achieved through the [`with_algorithmlogger`](@ref) function, and uses Julia's `with` function to set the [`ALGORITHM_LOGGER`](@ref) scoped value: -with(ALGORITHM_LOGGER => logger) do - state = solve(SqrtProblem(42.0), HeronAlgorithm(1.0, StopAfterIteration(8))) - println("Final ≈ sqrt(42): ", state.x) +```@example Heron +with_algorithmlogger(:PostStep => iter_printer) do + sqrt2 = heron_sqrt(2.0) end +nothing # hide ``` -### Timing the run +### Default logging contexts -Add actions for start timestamp and per‑step elapsed time: +The default `solve!` loop emits logging events at several key points during iteration: -```julia +| context | event | +| --------- | ----------------------------------- | +| :Start | The solver will start. | +| :PreStep | The solver is about to take a step. | +| :PostStep | The solver has taken a step. | +| :Stop | The solver has finished. | + +Any of these events can be hooked into to attach a logging action. +For example, we may expand on the previous example as follows: + +```@example Heron +start_printer = CallbackAction() do problem, algorithm, state + @printf("Start: x = %.12f\n", state.iterate) +end +stop_printer = CallbackAction() do problem, algorithm, state + @printf("Stop %3d: x = %.12f\n", state.iteration, state.iterate) +end + +with_algorithmlogger(:Start => start_printer, :PostStep => iter_printer, :Stop => stop_printer) do + sqrt2 = heron_sqrt(2.0) +end +nothing # hide +``` + +Furthermore, specific algorithms could emit events for custom contexts too. +We will come back to this in the section on the [`AlgorithmLogger`](@ref sec_algorithmlogger) design. + +### Timing execution + +Let's add timing information to see how long each iteration takes: + +```@example Heron start_time = Ref{Float64}(0.0) -record_start = CallbackAction() do alg, prob, st +record_start = CallbackAction() do problem, algorithm, state start_time[] = time() end -show_elapsed = CallbackAction() do alg, prob, st +show_elapsed = CallbackAction() do problem, algorithm, state dt = time() - start_time[] - @printf("Iter %3d elapsed = %.3fs\n", st.iteration, dt) + @printf(" elapsed = %.3fs\n", dt) end -logger = AlgorithmLogger( - :Init => record_start, - :PostStep => LogGroup([iter_printer, show_elapsed]), - :Stop => CallbackAction() do alg, prob, st - @printf("Done after %d iterations (total %.3fs)\n", st.iteration, time() - start_time[]) +with_algorithmlogger( + :Start => record_start, + :PostStep => show_elapsed, + :Stop => CallbackAction() do problem, algorithm, state + total = time() - start_time[] + @printf("Done after %d iterations (total %.3fs)\n", state.iteration, total) end, -) +) do + sqrt2 = heron_sqrt(2) +end +nothing # hide ``` -### Conditional logging (every N steps) +### Conditional logging -```julia -every_five = IfAction( - (prob, alg, st; kwargs...) -> st.iteration % 5 == 0, - CallbackAction() do alg, prob, st - println("Checkpoint at iteration ", st.iteration) - end, +Sometimes we only want to log at specific iterations. [`IfAction`](@ref) wraps another action behind a predicate: + +```@example Heron +every_two = IfAction( + (problem, algorithm, state; kwargs...) -> state.iteration % 2 == 0, + iter_printer, ) -logger = AlgorithmLogger(:PostStep => every_five) +with_algorithmlogger(:PostStep => every_two) do + sqrt2 = heron_sqrt(2) +end +nothing # hide ``` -### Capturing history for analysis +This prints only on even iterations, reducing output for long-running algorithms. -Instead of printing, store iterates in a custom action: +### Storing intermediate values -```julia +Instead of just printing, we can capture the entire trajectory for later analysis: + +```@example Heron struct CaptureHistory <: LoggingAction - xs::Vector{Float64} + iterates::Vector{Float64} end CaptureHistory() = CaptureHistory(Float64[]) -function AlgorithmsInterface.handle_message!(act::CaptureHistory, prob::SqrtProblem, alg::HeronAlgorithm, st::HeronState; kwargs...) - push!(act.xs, st.x) +function AlgorithmsInterface.handle_message!( + action::CaptureHistory, + problem::SqrtProblem, + algorithm::HeronAlgorithm, + state::HeronState; + kwargs... +) + push!(action.iterates, state.iterate) return nothing end history = CaptureHistory() -logger = AlgorithmLogger(:PostStep => history) -with(ALGORITHM_LOGGER => logger) do - solve(SqrtProblem(42.0), HeronAlgorithm(1.0, StopWhenStable(1e-10) & StopAfterIteration(200))) + +with_algorithmlogger(:PostStep => history) do + sqrt2 = heron_sqrt(2) end -println("Stored ", length(history.xs), " iterates") + +println("Stored ", length(history.iterates), " iterates") +println("First few values: ", history.iterates[1:min(3, end)]) ``` -You can later inspect convergence visually (plot `history.xs`). +You can later analyze convergence rates, plot trajectories, or export data—all without modifying the algorithm. + +### Combining multiple logging behaviors -### Multiple simultaneous behaviors +We can combine printing, timing, and storage simultaneously: -Group actions to avoid multiple context entries: +```@example Heron +history2 = CaptureHistory() + +with_algorithmlogger( + :Start => record_start, + :PostStep => GroupAction([iter_printer, history2]), + :Stop => CallbackAction() do problem, algorithm, state + @printf("Captured %d iterates in %.3fs\n", length(history2.iterates), time() - start_time[]) + end, +) do + sqrt2 = heron_sqrt(2) +end +nothing # hide +``` + +## Implementing custom LoggingActions + +While [`CallbackAction`](@ref) is convenient for quick instrumentation, custom types give more control and possibly better performance. +Let's implement a more sophisticated example: tracking iteration statistics. + +### The required interface + +To implement a custom [`LoggingAction`](@ref), you need: + +1. A concrete subtype of `LoggingAction`. +2. An implementation of [`handle_message!`](@ref) that defines the behavior. + +The signature of `handle_message!` is: ```julia -logger = AlgorithmLogger( - :PostStep => LogGroup([iter_printer, history, every_five]), +function handle_message!( + action::YourAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... ) + # Your logging logic here + return nothing +end ``` -### Adding custom contexts +The `kwargs...` can contain context-specific information, though the default contexts don't currently pass additional data. -Suppose we augment Heron's method with a fallback if `x` becomes non‑finite. We can log that: +### Example: Statistics collector -```julia -fallback_action = CallbackAction() do alg, prob, st; println("Fallback triggered at iteration ", st.iteration); end -logger = AlgorithmLogger(:Fallback => fallback_action, :PostStep => iter_printer) +Let's build an action that tracks statistics across iterations: -function safe_step!(prob::SqrtProblem, alg::HeronAlgorithm, st::HeronState) - isnan(st.x) && begin - handle_message(prob, alg, st, :Fallback) - st.x = alg.initial_guess - end - step!(prob, alg, st) +```@example Heron +mutable struct StatsCollector <: LoggingAction + count::Int # aggregate number of evaluations + sum::Float64 # sum of all intermediate values + sum_squares::Float64 # square sum of all intermediate values +end +StatsCollector() = StatsCollector(0, 0.0, 0.0) + +function AlgorithmsInterface.handle_message!( + action::StatsCollector, problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState; + kwargs... +) + action.count += 1 + action.sum += state.iterate + action.sum_squares += state.iterate^2 + return nothing +end + +function compute_stats(stats::StatsCollector) + n = stats.count + mean = stats.sum / n + variance = (stats.sum_squares / n) - mean^2 + return (mean=mean, variance=variance, count=n) end + +stats = StatsCollector() + +with_algorithmlogger(:PostStep => stats) do + sqrt2 = heron_sqrt(2.0; stopping_criterion = StopAfter(Millisecond(50))) +end + +result = compute_stats(stats) +println("Collected $(result.count) samples") +println("Mean iterate: $(result.mean)") +println("Variance: $(result.variance)") ``` -Just call `handle_message(prob, alg, st, :YourContext)` whenever the event occurs. +This pattern of collecting data during iteration and post-processing afterward is efficient and keeps the hot loop fast. -### Robustness: error isolation +## [The AlgorithmLogger](@id sec_algorithmlogger) -If a `LoggingAction` throws, the system catches and reports the error without aborting the algorithm. Keep actions side‑effect focused and fast; heavy processing can collect data during iteration and post‑process afterwards. +The [`AlgorithmLogger`](@ref) is the dispatcher that routes logging events to actions. +Understanding its design helps when adding custom logging contexts. -### Writing a new action type (summary statistics) +### How logging events are emitted + +Inside the `solve!` function, logging events are emitted at key points: ```julia -struct StatsCollector <: LoggingAction - n::Int - sum::Float64 +function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) + logger = algorithm_logger() + + initialize_state!(problem, algorithm, state; kwargs...) + emit_message(logger, problem, algorithm, state, :Start) + + while !is_finished!(problem, algorithm, state) + emit_message(logger, problem, algorithm, state, :PreStep) + + increment!(state) + step!(problem, algorithm, state) + + emit_message(logger, problem, algorithm, state, :PostStep) + end + + emit_message(logger, problem, algorithm, state, :Stop) + + return state end -StatsCollector() = StatsCollector(0, 0.0) +``` + +The [`emit_message`](@ref) function looks up the context (e.g., `:PostStep`) in the logger's action dictionary and calls `handle_message!` on the corresponding action. + +### Global enable/disable -function AlgorithmsInterface.handle_message!(act::StatsCollector, prob::SqrtProblem, alg::HeronAlgorithm, st::HeronState; kwargs...) - act.n += 1 - act.sum += st.x +For production runs or benchmarking, you can disable all logging globally: + +```@example Heron +# By default, logging is enabled: +println("Logging enabled: ", AlgorithmsInterface.get_global_logging_state()) +with_algorithmlogger(:PostStep => iter_printer) do + heron_sqrt(2.0) end +nothing # hide +``` -avg_action = CallbackAction() do alg, prob, st - # could query stats at :Stop using captured object +```@example Heron +# But, logging can also be disabled: +previous_state = AlgorithmsInterface.set_global_logging_state!(false) + +# This will not log anything, even with a logger configured +with_algorithmlogger(:PostStep => iter_printer) do + heron_sqrt(2.0) end -stats = StatsCollector() -logger = AlgorithmLogger(:PostStep => LogGroup([stats, iter_printer])) + +# Restore previous state +AlgorithmsInterface.set_global_logging_state!(previous_state) +nothing # hide ``` -At the end: +When logging is disabled globally, [`algorithm_logger`](@ref) returns `nothing`, and `emit_message` becomes a no-op with minimal overhead. -```julia -println("Average iterate value = ", stats.sum / stats.n) +### Error isolation + +If a `LoggingAction` throws an exception, the logging system catches it and reports an error without aborting the algorithm: + +```@example Heron +buggy_action = CallbackAction() do problem, algorithm, state + if state.iteration == 3 + error("Intentional logging error at iteration 3") + end + @printf("Iter %d\n", state.iteration) +end + +with_algorithmlogger(:PostStep => buggy_action) do + heron_sqrt(2.0) + println("Algorithm completed despite logging error") +end +``` + +This robustness ensures that bugs in logging code don't compromise the algorithm's correctness. + +## Adding custom logging contexts + +Algorithms can emit custom logging events for domain-specific scenarios. +For example, adaptive algorithms might emit events when step sizes are reduced, or when steps are rejected. +Here we will illustrate this by a slight adaptation of our algorithm, which could restart if convergence wasn't reached after 10 iterations. + +### Emitting custom events + +To emit a custom logging event from within your algorithm, call [`emit_message`](@ref): + +```@example Heron +function AlgorithmsInterface.step!(problem::SqrtProblem, algorithm::HeronAlgorithm, state::HeronState) + # Suppose we check for numerical issues + if !isfinite(state.iterate) || mod(state.iteration, 10) == 0 + emit_message(problem, algorithm, state, :Restart) + state.iterate = rand() # Reset the iterate an try again + end + + # Normal step + S = problem.S + x = state.iterate + state.iterate = 0.5 * (x + S / x) + return state +end +nothing # hide ``` -## Choosing what to store vs. print +Now users can attach actions to the `:Restart` context: + +```@example Heron +issue_counter = Ref(0) +issue_action = CallbackAction() do problem, algorithm, state + issue_counter[] += 1 + println("⚠️ Numerical issue detected at iteration ", state.iteration) +end + +with_algorithmlogger(:Restart => issue_action, :PostStep => iter_printer) do + sqrt2 = heron_sqrt(2.0; stopping_criterion = StopAfterIteration(30)) +end + +nothing # hide +``` + + +## Best practices -Guidelines: +### Performance considerations -* Use printing for immediate feedback (development / CLI runs). -* Store vectors / tables in custom actions for later analysis or plotting. -* Keep actions pure w.r.t. algorithm state (read but do not modify `state`). -* Prefer one `LogGroup` per context over many individual mappings. +* Logging actions may be fast or slow, since the overhead is only incurred when actually using them. +* Algorithms should be mindful of emitting events in hot loops. These events incur an overhead similar to accessing a `ScopedValue` (~10-100 ns), even when no logging action is registered. +* For expensive operations (plotting, I/O), it is often better to collect data during iteration and process afterward. +* Use `set_global_logging_state!(false)` for production benchmarks. + +### Guidelines for custom actions + +When designing custom logging actions for your algorithms: + +* It is good practice to avoid **modifying** the algorithm state, as this might leave the algorithm in an invalid state to continue running. +* The logging state and global state can be mutated as you see fit, but be mindful of properly initializing and resetting the state if so desired. +* If you need to influence the algorithm, use stopping criteria or modify the algorithm itself. +* For generic and reusable actions, document which properties they access from the `problem, algorithm, state` triplet, and be prepared to handle cases where these aren't present. + +### Guidelines for custom contexts + +When designing custom logging contexts for your algorithms: + +* Use descriptive symbol names (`:LineSearchFailed`, `:StepRejected`, `:Refined`). +* Document which contexts your algorithm emits and when. +* Keep context-specific data in `kwargs...` if needed (though the default contexts don't use this). +* Emit events at meaningful decision points, not in tight inner loops. + +## Summary + +Implementing logging involves three main components: + +1. **LoggingAction**: Define what happens when a logging event occurs. + - Use `CallbackAction` for quick inline functions. + - Implement custom subtypes for reusable, stateful logging. + - Implement `handle_message!(action, problem, algorithm, state; kwargs...)`. + +2. **AlgorithmLogger**: Map contexts (`:Start`, `:PostStep`, etc.) to actions. + - Construct with `with_algorithmlogger(:Context => action, ...)`. + - Use `GroupAction` to compose multiple actions at one context. + +3. **Custom contexts**: Emit domain-specific events from algorithms. + - Call `emit_message(problem, algorithm, state, :YourContext)`. + - Document custom contexts in your algorithm's documentation. + - Use descriptive symbol names. + +The logging system is designed for composability and zero-overhead when disabled, letting you instrument algorithms without compromising performance or code clarity. ## Reference API @@ -196,4 +490,11 @@ Private = true ## Wrap‑up -You have now seen: defining an algorithm (interface page), controlling halting (stopping criteria), and instrumenting execution (logging). Together these patterns encourage modular, testable iterative algorithm design. +You have now seen the three pillars of the AlgorithmsInterface: + +* [**Interface**](@ref sec_interface): Defining algorithms with `Problem`, `Algorithm`, and `State`. +* [**Stopping criteria**](@ref): Controlling when iteration halts with composable conditions. +* [**Logging**](@ref sec_logging): Instrumenting execution with flexible, composable actions. + +Together, these patterns encourage modular, testable, and maintainable iterative algorithm design. +You can now build algorithms that are easy to configure, monitor, and extend without invasive modifications to core logic. diff --git a/src/AlgorithmsInterface.jl b/src/AlgorithmsInterface.jl index f3b32a3..401dc0e 100644 --- a/src/AlgorithmsInterface.jl +++ b/src/AlgorithmsInterface.jl @@ -23,6 +23,8 @@ include("logging.jl") export Algorithm, Problem, State export StoppingCriterion, StoppingCriterionState export StopAfter, StopAfterIteration, StopWhenAll, StopWhenAny +export AlgorithmLogger, with_algorithmlogger, emit_message +export LoggingAction, CallbackAction, IfAction, GroupAction export is_finished, is_finished! export initialize_state, initialize_state! export step!, solve, solve! diff --git a/src/logging.jl b/src/logging.jl index 1d8f1c2..7f6b5e9 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -16,24 +16,26 @@ abstract type LoggingAction end handle_message!(action::LoggingAction, problem::Problem, algorithm::Algorithm, state::State; kwargs...) Entry-point for defining an implementation of how to handle a logging event for a given [`LoggingAction`](@ref). -""" handle_message!(::LoggingAction, ::Algorithm, ::Problem, ::State; kwargs...) +""" handle_message!(::LoggingAction, ::Problem, ::Algorithm, ::State; kwargs...) # Concrete LoggingActions # ----------------------- """ - LogGroup(actions::Vector{<:LoggingAction}) + GroupAction(actions::LoggingAction...) + GroupAction(actions::Vector{<:LoggingAction}) Concrete [`LoggingAction`](@ref) that can be used to sequentially perform each of the `actions`. """ -struct LogGroup{A <: LoggingAction} <: LoggingAction +struct GroupAction{A <: LoggingAction} <: LoggingAction actions::Vector{A} end +GroupAction(actions::LoggingAction...) = GroupAction(collect(LoggingAction, actions)) function handle_message!( - action::LogGroup, problem::Problem, algorithm::Algorithm, state::State; kwargs... + action::GroupAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... ) for child in action.actions - handle_message!(child, algorithm, problem, state; kwargs...) + handle_message!(child, problem, algorithm, state; kwargs...) end return nothing end @@ -44,7 +46,7 @@ end Concrete [`LoggingAction`](@ref) that handles a logging event through an arbitrary callback function. The callback function must have the following signature: ```julia -callback(algorithm, problem, state; kwargs...) = ... +callback(problem, algorithm, state; kwargs...) = ... ``` Here `kwargs...` are optional and can be filled out with context-specific information. """ @@ -55,7 +57,7 @@ end function handle_message!( action::CallbackAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... ) - action.callback(algorithm, problem, state; kwargs...) + action.callback(problem, algorithm, state; kwargs...) return nothing end @@ -66,7 +68,7 @@ Concrete [`LoggingAction`](@ref) that wraps another action and hides it behind a emitting logging events whenever the `predicate` evaluates to true. The `predicate` must have the signature: ```julia -predicate(algorithm, problem, state; kwargs...)::Bool +predicate(problem, algorithm, state; kwargs...)::Bool ``` """ struct IfAction{F, A <: LoggingAction} <: LoggingAction @@ -78,7 +80,7 @@ function handle_message!( action::IfAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... ) return action.predicate(problem, algorithm, state; kwargs...) ? - handle_message(action.action, problem, algorithm, state; kwargs...) : + handle_message!(action.action, problem, algorithm, state; kwargs...) : nothing end @@ -93,7 +95,6 @@ By default, the following events trigger a logging action with the given `contex | context | event | | --------- | ----------------------------------- | | :Start | The solver will start. | -| :Init | The solver has been initialized. | | :PreStep | The solver is about to take a step. | | :PostStep | The solver has taken a step. | | :Stop | The solver has finished. | @@ -105,8 +106,12 @@ See also the scoped value [`AlgorithmsInterface.algorithm_logger`](@ref). struct AlgorithmLogger actions::Dict{Symbol, LoggingAction} end -AlgorithmLogger(args...) = AlgorithmLogger(Dict{Symbol, LoggingAction}(args...)) +AlgorithmLogger(args::Pair...) = AlgorithmLogger(Dict{Symbol, LoggingAction}(args...)) +function with_algorithmlogger(f, args...) + logger = AlgorithmLogger(args...) + return with(f, ALGORITHM_LOGGER => logger) +end @doc """ get_global_logging_state() @@ -118,13 +123,12 @@ Retrieve or set the value to globally enable or disable the handling of logging const LOGGING_ENABLED = Ref(true) get_global_logging_state() = LOGGING_ENABLED[] -function set_global_logging_state(state::Bool) +function set_global_logging_state!(state::Bool) previous = LOGGING_ENABLED[] LOGGING_ENABLED[] = state return previous end - @doc """ algorithm_logger()::Union{AlgorithmLogger, Nothing} @@ -161,8 +165,11 @@ function emit_message( ) @noinline; @nospecialize action::LoggingAction = @something(get(alglogger.actions, context, nothing), return nothing) + + # Try-catch around logging to avoid stopping the algorithm when a logging action fails + # but still emit an error message try - handle_message!(action, problem, algorithm, state, args...; kwargs...) + handle_message!(action, problem, algorithm, state; kwargs...) catch err bt = catch_backtrace() @error "Error during the handling of a logging action" action exception = (err, bt) From d285b046187a29496ec18ed1664d9f9a0158ce01 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 11:44:09 -0500 Subject: [PATCH 15/23] clean up and finish logging docs --- docs/make.jl | 2 -- docs/src/interface.md | 2 +- docs/src/logging.md | 33 ++++++++++++++++------------- docs/src/stopping_criterion.md | 2 +- src/AlgorithmsInterface.jl | 15 ++++++++++---- src/logging.jl | 38 ++++++++++++++++++++++++---------- 6 files changed, 59 insertions(+), 33 deletions(-) diff --git a/docs/make.jl b/docs/make.jl index 7cf366e..1481694 100755 --- a/docs/make.jl +++ b/docs/make.jl @@ -52,8 +52,6 @@ makedocs(; ], expandfirst = ["interface.md", "stopping_criterion.md"], plugins = [bib, links], - warnonly = true - ) deploydocs(; repo = "github.com/JuliaManifolds/AlgorithmsInterface.jl", push_preview = true) #back to main env diff --git a/docs/src/interface.md b/docs/src/interface.md index e8ee7ba..18a573f 100644 --- a/docs/src/interface.md +++ b/docs/src/interface.md @@ -107,7 +107,7 @@ end ``` Note that we are only focussing on the actual algorithm, and *not* incrementing the iteration counter. -These kinds of bookkeeping should be handled by the [`increment!(state)`](@ref) function, which will by default already increment the iteration counter. +These kinds of bookkeeping should be handled by the [`AlgorithmsInterface.increment!`](@ref) function, which will by default already increment the iteration counter. The following generic functionality is therefore enough for our purposes, and does *not* need to be defined. Nevertheless, if additional bookkeeping would be desired, this can be achieved by overloading that function: diff --git a/docs/src/logging.md b/docs/src/logging.md index 1113330..fd2d97d 100644 --- a/docs/src/logging.md +++ b/docs/src/logging.md @@ -24,14 +24,14 @@ The logging system aims to achieve these goals by separating the logging logic i These parts can be roughly described as *events* and *actions*, where the logging system is responsible for mapping between them. Concretely, we have: -* **When do we log?** → an [`AlgorithmLogger`](@ref) mapping events to actions. -* **What happens when we log?** → a [`LoggingAction`](@ref). +* **When do we log?** → an [`with_algorithmlogger`](@ref) to control how to map events to actions. +* **What happens when we log?** → a [`LoggingAction`](@ref) to determine what to do when an event happens. This separation allows users to compose rich behaviors (printing, collecting statistics, plotting) without modifying algorithm code, and lets algorithm authors emit domain‑specific events. ## Using the default logging actions -Continuing from the [Stopping Criteria](@ref) page, we have our Heron's method implementation ready: +Continuing from the [Stopping Criteria](@ref sec_stopping) page, we have our Heron's method implementation ready: ```@example Heron using AlgorithmsInterface @@ -97,7 +97,7 @@ nothing # hide ``` To activate this logger, we wrap the section of code that we want to enable logging for, and map the `:PostStep` context to our action. -This is achieved through the [`with_algorithmlogger`](@ref) function, and uses Julia's `with` function to set the [`ALGORITHM_LOGGER`](@ref) scoped value: +This is achieved through the [`with_algorithmlogger`](@ref) function, which under the hood uses Julia's `with` function to manipulate a scoped value. ```@example Heron with_algorithmlogger(:PostStep => iter_printer) do @@ -246,7 +246,7 @@ Let's implement a more sophisticated example: tracking iteration statistics. To implement a custom [`LoggingAction`](@ref), you need: 1. A concrete subtype of `LoggingAction`. -2. An implementation of [`handle_message!`](@ref) that defines the behavior. +2. An implementation of [`AlgorithmsInterface.handle_message!`](@ref) that defines the behavior. The signature of `handle_message!` is: @@ -306,7 +306,7 @@ This pattern of collecting data during iteration and post-processing afterward i ## [The AlgorithmLogger](@id sec_algorithmlogger) -The [`AlgorithmLogger`](@ref) is the dispatcher that routes logging events to actions. +The [`AlgorithmsInterface.AlgorithmLogger`](@ref) is the dispatcher that routes logging events to actions. Understanding its design helps when adding custom logging contexts. ### How logging events are emitted @@ -315,21 +315,19 @@ Inside the `solve!` function, logging events are emitted at key points: ```julia function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) - logger = algorithm_logger() - initialize_state!(problem, algorithm, state; kwargs...) - emit_message(logger, problem, algorithm, state, :Start) + emit_message(problem, algorithm, state, :Start) while !is_finished!(problem, algorithm, state) - emit_message(logger, problem, algorithm, state, :PreStep) + emit_message(problem, algorithm, state, :PreStep) increment!(state) step!(problem, algorithm, state) - emit_message(logger, problem, algorithm, state, :PostStep) + emit_message(problem, algorithm, state, :PostStep) end - emit_message(logger, problem, algorithm, state, :Stop) + emit_message(problem, algorithm, state, :Stop) return state end @@ -364,7 +362,14 @@ AlgorithmsInterface.set_global_logging_state!(previous_state) nothing # hide ``` -When logging is disabled globally, [`algorithm_logger`](@ref) returns `nothing`, and `emit_message` becomes a no-op with minimal overhead. +This works since the default implementation of [`emit_message`](@ref) first retrieves the current logger through [`AlgorithmsInterface.algorithm_logger`](@ref): + +```julia +emit_message(problem, algorithm, state, context; kwargs...) = + emit_message(algorithm_logger(), problem, algorithm, state, context; kwargs...) +``` + +When logging is disabled globally, [`algorithm_logger`](@ref AlgorithmsInterface.algorithm_logger) returns `nothing`, and `emit_message` becomes a no-op with minimal overhead. ### Error isolation @@ -493,7 +498,7 @@ Private = true You have now seen the three pillars of the AlgorithmsInterface: * [**Interface**](@ref sec_interface): Defining algorithms with `Problem`, `Algorithm`, and `State`. -* [**Stopping criteria**](@ref): Controlling when iteration halts with composable conditions. +* [**Stopping criteria**](@ref sec_stopping): Controlling when iteration halts with composable conditions. * [**Logging**](@ref sec_logging): Instrumenting execution with flexible, composable actions. Together, these patterns encourage modular, testable, and maintainable iterative algorithm design. diff --git a/docs/src/stopping_criterion.md b/docs/src/stopping_criterion.md index 8d553bb..f03c3e4 100644 --- a/docs/src/stopping_criterion.md +++ b/docs/src/stopping_criterion.md @@ -2,7 +2,7 @@ CollapsedDocStrings = true ``` -# Stopping criteria +# [Stopping criteria](@id sec_stopping) Continuing the square‑root story from the [Interface](@ref sec_interface) page, we now decide **when** the iteration should halt. A stopping criterion encapsulates halting logic separately from the algorithm update rule. diff --git a/src/AlgorithmsInterface.jl b/src/AlgorithmsInterface.jl index 401dc0e..b2130d0 100644 --- a/src/AlgorithmsInterface.jl +++ b/src/AlgorithmsInterface.jl @@ -20,13 +20,20 @@ include("interface/interface.jl") include("stopping_criterion.jl") include("logging.jl") +# general interface export Algorithm, Problem, State +export initialize_state, initialize_state! + +export step!, solve, solve! + +# stopping criteria export StoppingCriterion, StoppingCriterionState export StopAfter, StopAfterIteration, StopWhenAll, StopWhenAny -export AlgorithmLogger, with_algorithmlogger, emit_message + +export is_finished, is_finished!, get_reason, indicates_convergence + +# Logging interface export LoggingAction, CallbackAction, IfAction, GroupAction -export is_finished, is_finished! -export initialize_state, initialize_state! -export step!, solve, solve! +export with_algorithmlogger, emit_message end # module AlgorithmsInterface diff --git a/src/logging.jl b/src/logging.jl index 7f6b5e9..bf12993 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -87,9 +87,27 @@ end # Algorithm Logger # ---------------- """ - AlgorithmLogger(context => action, ...) + AlgorithmLogger(context => action, ...) -> logger Logging transformer that handles the logic of dispatching logging events to logging actions. +This is implemented through `logger[context]`. + +See also the scoped value [`AlgorithmsInterface.algorithm_logger`](@ref). +""" +struct AlgorithmLogger + actions::Dict{Symbol, LoggingAction} +end +AlgorithmLogger(args::Pair...) = AlgorithmLogger(Dict{Symbol, LoggingAction}(args...)) + +Base.getindex(logger::AlgorithmLogger, context::Symbol) = get(logger.actions, context, nothing) + +""" + with_algorithmlogger(f, (context => action)::Pair{Symbol, LoggingAction}...) + with_algorithmlogger((context => action)::Pair{Symbol, LoggingAction}...) do + # insert arbitrary code here + end + +Run the given zero-argument function `f()` while mapping events of given `context`s to their respective `action`s. By default, the following events trigger a logging action with the given `context`: | context | event | @@ -99,16 +117,11 @@ By default, the following events trigger a logging action with the given `contex | :PostStep | The solver has taken a step. | | :Stop | The solver has finished. | -Specific algorithms can associate other events with other contexts. +However, further events and actions can be emitted through the [`emit_message`](@ref) interface. See also the scoped value [`AlgorithmsInterface.algorithm_logger`](@ref). """ -struct AlgorithmLogger - actions::Dict{Symbol, LoggingAction} -end -AlgorithmLogger(args::Pair...) = AlgorithmLogger(Dict{Symbol, LoggingAction}(args...)) - -function with_algorithmlogger(f, args...) +@inline function with_algorithmlogger(f, args...) logger = AlgorithmLogger(args...) return with(f, ALGORITHM_LOGGER => logger) end @@ -153,18 +166,21 @@ end emit_message(algorithm_logger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) -> nothing Use the current or the provided algorithm logger to handle the logging event of the given `context`. -The [`AlgorithmLogger`](@ref) is responsible for dispatching the correct events to the correct [`LoggingAction`](@ref)s. +The first signature should be favored as it correctly handles accessing the `logger` and respecting global toggles for enabling and disabling the logging system. + +The second signature should be used exclusively in (very) hot loops, where the overhead of [`AlgorithmsInterface.algorithm_logger()`](@ref) is too large. +In this case, you can manually extract the `algorithm_logger()` once outside of the hot loop. """ emit_message(problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) = emit_message(algorithm_logger(), problem, algorithm, state, context; kwargs...) emit_message(::Nothing, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs...) = nothing function emit_message( - alglogger::AlgorithmLogger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; + logger::AlgorithmLogger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; kwargs... ) @noinline; @nospecialize - action::LoggingAction = @something(get(alglogger.actions, context, nothing), return nothing) + action::LoggingAction = @something(logger[context], return nothing) # Try-catch around logging to avoid stopping the algorithm when a logging action fails # but still emit an error message From ba8739abfcf2bc026ffa9401a41cb95518216c5e Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 11:56:26 -0500 Subject: [PATCH 16/23] fix test --- test/newton.jl | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/newton.jl b/test/newton.jl index 93ecc0f..3a038aa 100644 --- a/test/newton.jl +++ b/test/newton.jl @@ -37,10 +37,10 @@ function initialize_state!( state.iteration = 0 state.iterate = 1.0 initialize_state!( - state.stopping_criterion_state, problem, algorithm, algorithm.stopping_criterion, + state.stopping_criterion_state, ) return state end From 78006a1a514716a4138c9ea4fb61c862d7bdb12c Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 12:47:13 -0500 Subject: [PATCH 17/23] add iteration test --- test/logging.jl | 57 ++++++++++++++++++++++++++++++++++++++++++++++++ test/runtests.jl | 4 ++++ 2 files changed, 61 insertions(+) create mode 100644 test/logging.jl diff --git a/test/logging.jl b/test/logging.jl new file mode 100644 index 0000000..96d8aed --- /dev/null +++ b/test/logging.jl @@ -0,0 +1,57 @@ +using Test +using AlgorithmsInterface + +# Dummy types for a minimal iterative algorithm +struct LogDummyProblem <: Problem end +struct LogDummyAlgorithm <: Algorithm + stopping_criterion +end +mutable struct LogDummyState{S <: StoppingCriterionState} <: State + iterate::Float64 + iteration::Int + stopping_criterion_state::S +end + +# State initialization for the dummy algorithm +function AlgorithmsInterface.initialize_state(problem::LogDummyProblem, algorithm::LogDummyAlgorithm; kwargs...) + sc_state = initialize_state(problem, algorithm, algorithm.stopping_criterion; kwargs...) + return LogDummyState(0.0, 0, sc_state) +end +function AlgorithmsInterface.initialize_state!( + problem::LogDummyProblem, + algorithm::LogDummyAlgorithm, + state::LogDummyState; + kwargs... + ) + initialize_state!(problem, algorithm, algorithm.stopping_criterion, state.stopping_criterion_state; kwargs...) + state.iterate = 0.0 + state.iteration = 0 + return state +end + +# One trivial step per iteration (not relevant for the logging test) +function AlgorithmsInterface.step!( + ::LogDummyProblem, + ::LogDummyAlgorithm, + state::LogDummyState, + ) + state.iterate += 1.0 + return state +end + +@testset "CallbackAction logs iteration on each step" begin + problem = LogDummyProblem() + algorithm = LogDummyAlgorithm(StopAfterIteration(3)) + + # Action that logs the current iteration number at :PostStep + iter_logger = CallbackAction() do problem, algorithm, state + @info "Iter $(state.iteration)" + end + + # Expect exactly three info logs for iterations 1, 2, 3 + @test_logs (:info, "Iter 1") (:info, "Iter 2") (:info, "Iter 3") begin + with_algorithmlogger(:PostStep => iter_logger) do + solve(problem, algorithm) + end + end +end diff --git a/test/runtests.jl b/test/runtests.jl index a6d423f..18b9b80 100644 --- a/test/runtests.jl +++ b/test/runtests.jl @@ -12,6 +12,10 @@ end include("stopping_criterion.jl") end +@safetestset "Logging Infrastructure" begin + include("logging.jl") +end + @safetestset "Aqua" begin using AlgorithmsInterface, Aqua Aqua.test_all(AlgorithmsInterface) From e4fe20ed8bc8101fea20cac03b92ad619be9814b Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 12:55:20 -0500 Subject: [PATCH 18/23] add error test --- test/logging.jl | 23 +++++++++++++++++++++++ 1 file changed, 23 insertions(+) diff --git a/test/logging.jl b/test/logging.jl index 96d8aed..2a336ea 100644 --- a/test/logging.jl +++ b/test/logging.jl @@ -55,3 +55,26 @@ end end end end + +@testset "Logging errors are caught and don't crash" begin + problem = LogDummyProblem() + algorithm = LogDummyAlgorithm(StopAfterIteration(3)) + + # Action that throws on the second iteration + flaky_logger = CallbackAction() do problem, algorithm, state + if state.iteration == 2 + error("Boom") + else + @info "Iter $(state.iteration)" + end + end + + # We expect: + # - an error log emitted by the logging infrastructure on iter 2 + # - info logs for iterations 1 and 3 + @test_logs (:info, "Iter 1") (:error, "Error during the handling of a logging action") (:info, "Iter 3") begin + with_algorithmlogger(:PostStep => flaky_logger) do + solve(problem, algorithm) + end + end +end From 51f7a687964523e9e759bf2af705e41ff9c8b6a8 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 13:04:52 -0500 Subject: [PATCH 19/23] Add test for `IfAction` --- test/logging.jl | 21 +++++++++++++++++++++ 1 file changed, 21 insertions(+) diff --git a/test/logging.jl b/test/logging.jl index 2a336ea..bbdbb43 100644 --- a/test/logging.jl +++ b/test/logging.jl @@ -78,3 +78,24 @@ end end end end + +@testset "IfAction only logs on even iterations" begin + problem = LogDummyProblem() + algorithm = LogDummyAlgorithm(StopAfterIteration(4)) + + # Callback that logs the iteration + iter_logger = CallbackAction() do problem, algorithm, state + @info "Even Iter $(state.iteration)" + end + + # Predicate: only log on even iterations + even_predicate = (problem, algorithm, state; kwargs...) -> state.iteration % 2 == 0 + if_logger = IfAction(even_predicate, iter_logger) + + # Expect logs only for iterations 2 and 4 + @test_logs (:info, "Even Iter 2") (:info, "Even Iter 4") begin + with_algorithmlogger(:PostStep => if_logger) do + solve(problem, algorithm) + end + end +end From c356152cb8d907bd7a6396fb2df41d7eecaf7442 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 13:06:22 -0500 Subject: [PATCH 20/23] Add GroupAction test --- test/logging.jl | 24 ++++++++++++++++++++++++ 1 file changed, 24 insertions(+) diff --git a/test/logging.jl b/test/logging.jl index bbdbb43..4468286 100644 --- a/test/logging.jl +++ b/test/logging.jl @@ -99,3 +99,27 @@ end end end end + +@testset "GroupAction logs multiple actions" begin + problem = LogDummyProblem() + algorithm = LogDummyAlgorithm(StopAfterIteration(2)) + + # First logger + logger1 = CallbackAction() do problem, algorithm, state + @info "Logger1 Iter $(state.iteration)" + end + + # Second logger + logger2 = CallbackAction() do problem, algorithm, state + @info "Logger2 Iter $(state.iteration)" + end + + group_logger = GroupAction(logger1, logger2) + + # Expect both loggers to log for each iteration + @test_logs (:info, "Logger1 Iter 1") (:info, "Logger2 Iter 1") (:info, "Logger1 Iter 2") (:info, "Logger2 Iter 2") begin + with_algorithmlogger(:PostStep => group_logger) do + solve(problem, algorithm) + end + end +end From bd1d90005b900c1e1b46e955c636970b3de762a8 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Fri, 7 Nov 2025 13:15:16 -0500 Subject: [PATCH 21/23] add global toggle test --- test/logging.jl | 39 +++++++++++++++++++++++++++++++++++++++ 1 file changed, 39 insertions(+) diff --git a/test/logging.jl b/test/logging.jl index 4468286..986791a 100644 --- a/test/logging.jl +++ b/test/logging.jl @@ -123,3 +123,42 @@ end end end end + +@testset "Global logging toggle disables all logging" begin + problem = LogDummyProblem() + algorithm = LogDummyAlgorithm(StopAfterIteration(3)) + + # Action that logs the current iteration number + iter_logger = CallbackAction() do problem, algorithm, state + @info "Iter $(state.iteration)" + end + + # Save the current global logging state + previous_state = AlgorithmsInterface.get_global_logging_state() + @test previous_state == true # logging should be enabled by default + + # Disable logging globally + AlgorithmsInterface.set_global_logging_state!(false) + @test AlgorithmsInterface.get_global_logging_state() == false + + # Even with a logger configured, no logs should be emitted + @test_logs begin + with_algorithmlogger(:PostStep => iter_logger) do + solve(problem, algorithm) + end + end + + # Re-enable logging + AlgorithmsInterface.set_global_logging_state!(true) + @test AlgorithmsInterface.get_global_logging_state() == true + + # Now logging should work again + @test_logs (:info, "Iter 1") (:info, "Iter 2") (:info, "Iter 3") begin + with_algorithmlogger(:PostStep => iter_logger) do + solve(problem, algorithm) + end + end + + # Restore the original state (in case it was different) + AlgorithmsInterface.set_global_logging_state!(previous_state) +end From 703284a6d5c1e08766e9bf95813da5c56a7064ef Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Sat, 8 Nov 2025 07:56:35 -0500 Subject: [PATCH 22/23] `GroupAction` -> `ActionGroup` --- docs/src/logging.md | 4 ++-- src/AlgorithmsInterface.jl | 2 +- src/logging.jl | 10 +++++----- test/logging.jl | 4 ++-- 4 files changed, 10 insertions(+), 10 deletions(-) diff --git a/docs/src/logging.md b/docs/src/logging.md index fd2d97d..c167abb 100644 --- a/docs/src/logging.md +++ b/docs/src/logging.md @@ -226,7 +226,7 @@ history2 = CaptureHistory() with_algorithmlogger( :Start => record_start, - :PostStep => GroupAction([iter_printer, history2]), + :PostStep => ActionGroup(iter_printer, history2), :Stop => CallbackAction() do problem, algorithm, state @printf("Captured %d iterates in %.3fs\n", length(history2.iterates), time() - start_time[]) end, @@ -473,7 +473,7 @@ Implementing logging involves three main components: 2. **AlgorithmLogger**: Map contexts (`:Start`, `:PostStep`, etc.) to actions. - Construct with `with_algorithmlogger(:Context => action, ...)`. - - Use `GroupAction` to compose multiple actions at one context. + - Use `ActionGroup` to compose multiple actions at one context. 3. **Custom contexts**: Emit domain-specific events from algorithms. - Call `emit_message(problem, algorithm, state, :YourContext)`. diff --git a/src/AlgorithmsInterface.jl b/src/AlgorithmsInterface.jl index b2130d0..2a9ed68 100644 --- a/src/AlgorithmsInterface.jl +++ b/src/AlgorithmsInterface.jl @@ -33,7 +33,7 @@ export StopAfter, StopAfterIteration, StopWhenAll, StopWhenAny export is_finished, is_finished!, get_reason, indicates_convergence # Logging interface -export LoggingAction, CallbackAction, IfAction, GroupAction +export LoggingAction, CallbackAction, IfAction, ActionGroup export with_algorithmlogger, emit_message end # module AlgorithmsInterface diff --git a/src/logging.jl b/src/logging.jl index bf12993..b1b9151 100644 --- a/src/logging.jl +++ b/src/logging.jl @@ -21,18 +21,18 @@ Entry-point for defining an implementation of how to handle a logging event for # Concrete LoggingActions # ----------------------- """ - GroupAction(actions::LoggingAction...) - GroupAction(actions::Vector{<:LoggingAction}) + ActionGroup(actions::LoggingAction...) + ActionGroup(actions::Vector{<:LoggingAction}) Concrete [`LoggingAction`](@ref) that can be used to sequentially perform each of the `actions`. """ -struct GroupAction{A <: LoggingAction} <: LoggingAction +struct ActionGroup{A <: LoggingAction} <: LoggingAction actions::Vector{A} end -GroupAction(actions::LoggingAction...) = GroupAction(collect(LoggingAction, actions)) +ActionGroup(actions::LoggingAction...) = ActionGroup(collect(LoggingAction, actions)) function handle_message!( - action::GroupAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... + action::ActionGroup, problem::Problem, algorithm::Algorithm, state::State; kwargs... ) for child in action.actions handle_message!(child, problem, algorithm, state; kwargs...) diff --git a/test/logging.jl b/test/logging.jl index 986791a..e31cf1c 100644 --- a/test/logging.jl +++ b/test/logging.jl @@ -100,7 +100,7 @@ end end end -@testset "GroupAction logs multiple actions" begin +@testset "ActionGroup logs multiple actions" begin problem = LogDummyProblem() algorithm = LogDummyAlgorithm(StopAfterIteration(2)) @@ -114,7 +114,7 @@ end @info "Logger2 Iter $(state.iteration)" end - group_logger = GroupAction(logger1, logger2) + group_logger = ActionGroup(logger1, logger2) # Expect both loggers to log for each iteration @test_logs (:info, "Logger1 Iter 1") (:info, "Logger2 Iter 1") (:info, "Logger1 Iter 2") (:info, "Logger2 Iter 2") begin From 042a3690d2cd1704e7d2e47570cea6bff2b0ecf5 Mon Sep 17 00:00:00 2001 From: Lukas Devos Date: Sat, 8 Nov 2025 12:11:52 -0500 Subject: [PATCH 23/23] Update interface.md Co-authored-by: Ronny Bergmann --- docs/src/interface.md | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/docs/src/interface.md b/docs/src/interface.md index 18a573f..9d4817a 100644 --- a/docs/src/interface.md +++ b/docs/src/interface.md @@ -38,7 +38,9 @@ Our running example is Heron's / Babylonian method for estimating $\sqrt{S}$. (see also the concise background on Wikipedia: [Babylonian method (Heron's method)](https://en.wikipedia.org/wiki/Methods_of_computing_square_roots#Babylonian_method)): Starting from an initial guess $x_0$, we may converge to the solution by iterating: -$$x_{k+1} = \frac{1}{2}\left(x_k + \frac{S}{x_k}\right)$$ +```math +x_{k+1} = \frac{1}{2}\left(x_k + \frac{S}{x_k}\right) +``` We therefore suggest the following concrete implementations of the abstract types provided by this package: They are illustrative; various performance and generality questions will be left unaddressed to keep this example simple.