diff --git a/Project.toml b/Project.toml index 6cf9f86..2c4fb10 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.10" SafeTestsets = "0.1" +ScopedValues = "1.5.0" Test = "1.10" julia = "1.10" diff --git a/docs/make.jl b/docs/make.jl index dc79dac..1481694 100755 --- a/docs/make.jl +++ b/docs/make.jl @@ -46,9 +46,11 @@ 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], ) deploydocs(; repo = "github.com/JuliaManifolds/AlgorithmsInterface.jl", push_preview = true) diff --git a/docs/src/interface.md b/docs/src/interface.md index c6bb211..9d4817a 100644 --- a/docs/src/interface.md +++ b/docs/src/interface.md @@ -1,28 +1,145 @@ -# The algorithm interface +```@meta +CollapsedDocStrings = true +``` + +# [The algorithm interface](@id sec_interface) + +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. + +Why an “interface” for algorithms? Iterative numerical methods nearly always share the +same moving pieces: + +* 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. -## General design ideas +Bundling these together loosely without forcing one giant monolithic type makes it easier to: -The interface this package provides is based on three ingredients of running an algorithm -consists of: +* 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 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. + +## [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: + +```math +x_{k+1} = \frac{1}{2}\left(x_k + \frac{S}{x_k}\right) +``` -* 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. +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. -The combination of the static information should be enough to initialize the varying data. +### Algorithm types -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. +```@example Heron +using AlgorithmsInterface -The order of arguments is given by two ideas +struct SqrtProblem <: Problem + S::Float64 # number whose square root we seek +end -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)`. +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 [`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: + +```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 +148,7 @@ Order = [:type, :function] Private = true ``` -## Algorithm +### Algorithm ```@autodocs Modules = [AlgorithmsInterface] @@ -40,7 +157,7 @@ Order = [:type, :function] Private = true ``` -## Problem +### Problem ```@autodocs Modules = [AlgorithmsInterface] @@ -49,11 +166,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/docs/src/logging.md b/docs/src/logging.md new file mode 100644 index 0000000..c167abb --- /dev/null +++ b/docs/src/logging.md @@ -0,0 +1,505 @@ +```@meta +CollapsedDocStrings = true +``` + +# [Logging](@id sec_logging) + +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 [`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 sec_stopping) page, we have our Heron's method implementation ready: + +```@example Heron +using AlgorithmsInterface +using Printf +using Dates # hide + +struct SqrtProblem <: Problem + S::Float64 +end + +struct HeronAlgorithm <: Algorithm + stopping_criterion +end + +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 +``` + +It is already interesting to note that there are no further modifications necessary to start leveraging the logging system. + +### Basic iteration printing + +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 +``` + +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, which under the hood uses Julia's `with` function to manipulate a scoped value. + +```@example Heron +with_algorithmlogger(:PostStep => iter_printer) do + sqrt2 = heron_sqrt(2.0) +end +nothing # hide +``` + +### Default logging contexts + +The default `solve!` loop emits logging events at several key points during iteration: + +| 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 problem, algorithm, state + start_time[] = time() +end + +show_elapsed = CallbackAction() do problem, algorithm, state + dt = time() - start_time[] + @printf(" elapsed = %.3fs\n", dt) +end + +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 + +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, +) + +with_algorithmlogger(:PostStep => every_two) do + sqrt2 = heron_sqrt(2) +end +nothing # hide +``` + +This prints only on even iterations, reducing output for long-running algorithms. + +### Storing intermediate values + +Instead of just printing, we can capture the entire trajectory for later analysis: + +```@example Heron +struct CaptureHistory <: LoggingAction + iterates::Vector{Float64} +end +CaptureHistory() = CaptureHistory(Float64[]) + +function AlgorithmsInterface.handle_message!( + action::CaptureHistory, + problem::SqrtProblem, + algorithm::HeronAlgorithm, + state::HeronState; + kwargs... +) + push!(action.iterates, state.iterate) + return nothing +end + +history = CaptureHistory() + +with_algorithmlogger(:PostStep => history) do + sqrt2 = heron_sqrt(2) +end + +println("Stored ", length(history.iterates), " iterates") +println("First few values: ", history.iterates[1:min(3, end)]) +``` + +You can later analyze convergence rates, plot trajectories, or export data—all without modifying the algorithm. + +### Combining multiple logging behaviors + +We can combine printing, timing, and storage simultaneously: + +```@example Heron +history2 = CaptureHistory() + +with_algorithmlogger( + :Start => record_start, + :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, +) 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 [`AlgorithmsInterface.handle_message!`](@ref) that defines the behavior. + +The signature of `handle_message!` is: + +```julia +function handle_message!( + action::YourAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... +) + # Your logging logic here + return nothing +end +``` + +The `kwargs...` can contain context-specific information, though the default contexts don't currently pass additional data. + +### Example: Statistics collector + +Let's build an action that tracks statistics across iterations: + +```@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)") +``` + +This pattern of collecting data during iteration and post-processing afterward is efficient and keeps the hot loop fast. + +## [The AlgorithmLogger](@id sec_algorithmlogger) + +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 + +Inside the `solve!` function, logging events are emitted at key points: + +```julia +function solve!(problem::Problem, algorithm::Algorithm, state::State; kwargs...) + initialize_state!(problem, algorithm, state; kwargs...) + emit_message(problem, algorithm, state, :Start) + + while !is_finished!(problem, algorithm, state) + emit_message(problem, algorithm, state, :PreStep) + + increment!(state) + step!(problem, algorithm, state) + + emit_message(problem, algorithm, state, :PostStep) + end + + emit_message(problem, algorithm, state, :Stop) + + return state +end +``` + +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 + +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 +``` + +```@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 + +# Restore previous state +AlgorithmsInterface.set_global_logging_state!(previous_state) +nothing # hide +``` + +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 + +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 +``` + +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 + +### Performance considerations + +* 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 `ActionGroup` 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 + +Auto‑generated documentation for logging infrastructure follows. + +```@autodocs +Modules = [AlgorithmsInterface] +Pages = ["logging.jl"] +Order = [:type, :function] +Private = true +``` + +## Wrap‑up + +You have now seen the three pillars of the AlgorithmsInterface: + +* [**Interface**](@ref sec_interface): Defining algorithms with `Problem`, `Algorithm`, and `State`. +* [**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. +You can now build algorithms that are easy to configure, monitor, and extend without invasive modifications to core logic. diff --git a/docs/src/stopping_criterion.md b/docs/src/stopping_criterion.md index 6f5917c..f03c3e4 100644 --- a/docs/src/stopping_criterion.md +++ b/docs/src/stopping_criterion.md @@ -1,8 +1,281 @@ -# Stopping criterion +```@meta +CollapsedDocStrings = true +``` + +# [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. + +## 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/AlgorithmsInterface.jl b/src/AlgorithmsInterface.jl index 8dd052a..2a9ed68 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") @@ -16,12 +18,22 @@ include("interface/state.jl") include("interface/interface.jl") include("stopping_criterion.jl") +include("logging.jl") +# general interface export Algorithm, Problem, State -export StoppingCriterion, StoppingCriterionState -export StopAfter, StopAfterIteration, StopWhenAll, StopWhenAny -export is_finished, is_finished! export initialize_state, initialize_state! + export step!, solve, solve! +# stopping criteria +export StoppingCriterion, StoppingCriterionState +export StopAfter, StopAfterIteration, StopWhenAll, StopWhenAny + +export is_finished, is_finished!, get_reason, indicates_convergence + +# Logging interface +export LoggingAction, CallbackAction, IfAction, ActionGroup +export with_algorithmlogger, emit_message + end # module AlgorithmsInterface diff --git a/src/interface/interface.jl b/src/interface/interface.jl index c72c8ca..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. @@ -43,11 +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...) + emit_message(logger, problem, algorithm, state, :Start) + + # main body of the algorithm while !is_finished!(problem, algorithm, state) + # logging event between convergence check and algorithm step + emit_message(logger, problem, algorithm, state, :PreStep) + + # algorithm step increment!(state) step!(problem, algorithm, state) + + # logging event between algorithm step and convergence check + emit_message(logger, problem, algorithm, state, :PostStep) end + + # emit message about finished state + emit_message(logger, problem, algorithm, state, :Stop) + return state end 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/logging.jl b/src/logging.jl new file mode 100644 index 0000000..b1b9151 --- /dev/null +++ b/src/logging.jl @@ -0,0 +1,194 @@ +# 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 to handle the logging event: + +- [`handle_message!(action, problem, algorithm, state, args...; kwargs...)`](@ref handle_message!) +""" +abstract type LoggingAction end + +@doc """ + 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, ::Problem, ::Algorithm, ::State; kwargs...) + +# Concrete LoggingActions +# ----------------------- +""" + ActionGroup(actions::LoggingAction...) + ActionGroup(actions::Vector{<:LoggingAction}) + +Concrete [`LoggingAction`](@ref) that can be used to sequentially perform each of the `actions`. +""" +struct ActionGroup{A <: LoggingAction} <: LoggingAction + actions::Vector{A} +end +ActionGroup(actions::LoggingAction...) = ActionGroup(collect(LoggingAction, actions)) + +function handle_message!( + action::ActionGroup, problem::Problem, algorithm::Algorithm, state::State; kwargs... + ) + for child in action.actions + handle_message!(child, problem, algorithm, state; kwargs...) + end + return nothing +end + +""" + 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(problem, algorithm, state; kwargs...) = ... +``` +Here `kwargs...` are optional and can be filled out with context-specific information. +""" +struct CallbackAction{F} <: LoggingAction + callback::F +end + +function handle_message!( + action::CallbackAction, problem::Problem, algorithm::Algorithm, state::State; kwargs... + ) + action.callback(problem, algorithm, state; kwargs...) + 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(problem, algorithm, state; kwargs...)::Bool +``` +""" +struct IfAction{F, A <: LoggingAction} <: LoggingAction + predicate::F + action::A +end + +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 + +# Algorithm Logger +# ---------------- +""" + 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 | +| --------- | ----------------------------------- | +| :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. | + +However, further events and actions can be emitted through the [`emit_message`](@ref) interface. + +See also the scoped value [`AlgorithmsInterface.algorithm_logger`](@ref). +""" +@inline function with_algorithmlogger(f, args...) + logger = AlgorithmLogger(args...) + return with(f, ALGORITHM_LOGGER => logger) +end + +@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) + +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 + +const ALGORITHM_LOGGER = ScopedValue(AlgorithmLogger()) + +function algorithm_logger() + LOGGING_ENABLED[] || return nothing + logger = ALGORITHM_LOGGER[] + isempty(logger.actions) && return nothing + return logger +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 + +Use the current or the provided algorithm logger to handle the logging event of the given `context`. +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( + logger::AlgorithmLogger, problem::Problem, algorithm::Algorithm, state::State, context::Symbol; + kwargs... + ) + @noinline; @nospecialize + 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 + try + 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) + end + return nothing +end diff --git a/src/stopping_criterion.jl b/src/stopping_criterion.jl index 2470fdf..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`, @@ -237,7 +236,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) @@ -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 diff --git a/test/logging.jl b/test/logging.jl new file mode 100644 index 0000000..e31cf1c --- /dev/null +++ b/test/logging.jl @@ -0,0 +1,164 @@ +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 + +@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 + +@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 + +@testset "ActionGroup 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 = 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 + with_algorithmlogger(:PostStep => group_logger) do + solve(problem, algorithm) + 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 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 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)