Always show convergence bottlenecks (#1636)

Fixes #1593. Follow-up of #1440.
Deltares · Jul 22, 2024 · bc97d23 · bc97d23
1 parent 0e8e657
commit bc97d23
Show file tree

Hide file tree

Showing 5 changed files with 41 additions and 37 deletions.
diff --git a/core/src/Ribasim.jl b/core/src/Ribasim.jl
@@ -39,7 +39,7 @@ using ForwardDiff: pickchunksize
 using Graphs:
     DiGraph, Edge, edges, inneighbors, nv, outneighbors, induced_subgraph, is_connected
 using Legolas: Legolas, @schema, @version, validate, SchemaVersion, declared
-using Logging: with_logger, LogLevel, AbstractLogger
+using Logging: with_logger, @logmsg, LogLevel, AbstractLogger
 using MetaGraphsNext:
     MetaGraphsNext,
     MetaGraph,

diff --git a/core/src/logging.jl b/core/src/logging.jl
@@ -26,3 +26,29 @@ function setup_logger(;
         LoggingExtras.TeeLogger(file_logger, terminal_logger),
     )
 end
+
+function log_bottlenecks(model; converged::Bool)
+    (; cache, p, u) = model.integrator
+    (; basin) = p
+
+    level = converged ? LoggingExtras.Info : LoggingExtras.Warn
+
+    # Indicate convergence bottlenecks if possible with the current algorithm
+    if hasproperty(cache, :nlsolver)
+        storage_error = @. abs(cache.nlsolver.cache.atmp.storage / u.storage)
+        perm = sortperm(storage_error; rev = true)
+        errors = Pair{Symbol, Float64}[]
+        for i in perm
+            node_id = Symbol(basin.node_id[i])
+            error = storage_error[i]
+            if error < model.config.solver.reltol
+                break
+            end
+            push!(errors, node_id => error)
+        end
+        @logmsg level "Convergence bottlenecks in descending order of severity:" errors...
+    else
+        algorithm = model.config.solver.algorithm
+        @logmsg level "Convergence bottlenecks are not shown for the chosen solver algorithm." algorithm
+    end
+end
diff --git a/core/src/main.jl b/core/src/main.jl
@@ -41,39 +41,19 @@ function main(toml_path::AbstractString)::Cint
                 end
                 @info "Starting a Ribasim simulation." cli.ribasim_version starttime endtime
                 model = run(config)
+
                 if successful_retcode(model)
+                    log_bottlenecks(model; converged = true)
                     @info "The model finished successfully"
                     return 0
-                end
-
-                t = datetime_since(model.integrator.t, starttime)
-                retcode = model.integrator.sol.retcode
-                @error "The model exited at model time $t with return code $retcode.\nSee https://docs.sciml.ai/DiffEqDocs/stable/basics/solution/#retcodes"
-
-                (; cache, p, u) = model.integrator
-                (; basin) = p
-                # Indicate convergence bottlenecks if possible with the current algorithm
-                if hasproperty(cache, :nlsolver)
-                    storage_error = @. abs(cache.nlsolver.cache.atmp.storage / u.storage)
-                    perm = sortperm(storage_error; rev = true)
-                    println(
-                        "The following basins were identified as convergence bottlenecks (in descending order of severity):",
-                    )
-                    for i in perm
-                        node_id = basin.node_id[i]
-                        error = storage_error[i]
-                        if error < config.solver.reltol
-                            break
-                        end
-                        println("$node_id, error = $error")
-                    end
                 else
-                    algorithm = model.config.solver_algorithm
-                    println(
-                        "The current algorithm ($algorithm) does not support indicating convergence bottlenecks, for that try a different one.",
-                    )
+                    log_bottlenecks(model; converged = false)
+                    t = datetime_since(model.integrator.t, starttime)
+                    retcode = model.integrator.sol.retcode
+                    @error """The model exited at model time $t with return code $retcode.
+                    See https://docs.sciml.ai/DiffEqDocs/stable/basics/solution/#retcodes"""
+                    return 1
                 end
-                return 1
             end
         end
     catch

diff --git a/core/test/main_test.jl b/core/test/main_test.jl
@@ -24,4 +24,5 @@
         @show backtrace
     end
     @test occursin("version in the TOML config file does not match", output)
+    @test occursin("Info: Convergence bottlenecks in descending order of severity:", output)
 end
diff --git a/core/test/validation_test.jl b/core/test/validation_test.jl
@@ -428,19 +428,16 @@ end
 end
 
 @testitem "Convergence bottleneck" begin
+    using Logging
     using IOCapture: capture
     toml_path =
         normpath(@__DIR__, "../../generated_testmodels/invalid_unstable/ribasim.toml")
     @test ispath(toml_path)
+
     (; output) = capture() do
         Ribasim.main(toml_path)
     end
-    output = split(output, "\n")[(end - 4):end]
-    @test startswith(
-        output[1],
-        "The following basins were identified as convergence bottlenecks",
-    )
-    @test startswith(output[2], "Basin #11")
-    @test startswith(output[3], "Basin #31")
-    @test startswith(output[4], "Basin #51")
+
+    @test occursin("Warning: Convergence bottlenecks in descending order of severity:", output)
+    @test occursin("Basin #11 = ", output)
 end