From 75f543088f066c3573ea97209969c924ac13b7f7 Mon Sep 17 00:00:00 2001 From: Marnix Kraus Date: Fri, 15 Dec 2023 16:21:57 +0100 Subject: [PATCH] Test that checks if something was written in the file logger Close the logger when done --- core/src/logging.jl | 24 +++++++++++++++++++---- core/src/main.jl | 1 + core/test/logging_test.jl | 40 +++++++++++++++++++++++++++++++++++++++ 3 files changed, 61 insertions(+), 4 deletions(-) diff --git a/core/src/logging.jl b/core/src/logging.jl index f8562f2cb..77629280b 100644 --- a/core/src/logging.jl +++ b/core/src/logging.jl @@ -1,10 +1,16 @@ -function is_current_module(log)::Bool +const LogMessageType = + @NamedTuple{level::LogLevel, _module::Module, group::Symbol, id::Symbol} + +function is_current_module(log::LogMessageType)::Bool (log._module == @__MODULE__) || (parentmodule(log._module) == @__MODULE__) || - log._module == OrdinaryDiffEq # for the progress bar + log._module == OrdinaryDiffEq# for the progress bar end -function setup_logger(config::Config)::AbstractLogger +function setup_logger( + config::Config; + module_filter_function::Function = is_current_module, +)::AbstractLogger file_logger = LoggingExtras.MinLevelLogger( LoggingExtras.FileLogger(results_path(config, "ribasim.log")), config.logging.verbosity, @@ -14,7 +20,17 @@ function setup_logger(config::Config)::AbstractLogger LogLevel(-1), # To include progress bar ) return LoggingExtras.EarlyFilteredLogger( - is_current_module, + module_filter_function, LoggingExtras.TeeLogger(file_logger, terminal_logger), ) end + +function close(logger::AbstractLogger) + if hasfield(typeof(logger), :logger) + close(logger.logger) + elseif hasfield(typeof(logger), :loggers) + foreach(close, logger.loggers) + elseif hasfield(typeof(logger), :stream) && !isa(logger, TerminalLogger) + Base.close(logger.stream) + end +end diff --git a/core/src/main.jl b/core/src/main.jl index dded145d5..c017b5454 100644 --- a/core/src/main.jl +++ b/core/src/main.jl @@ -28,6 +28,7 @@ function main(ARGS)::Cint model = with_logger(logger) do Ribasim.run(config) end + Ribasim.close(logger) return if successful_retcode(model) println("The model finished successfully") 0 diff --git a/core/test/logging_test.jl b/core/test/logging_test.jl index 89bffbd67..375eebe37 100644 --- a/core/test/logging_test.jl +++ b/core/test/logging_test.jl @@ -13,6 +13,8 @@ @test Logging.shouldlog(logger, Logging.Info, Ribasim, nothing, "message") @test Logging.shouldlog(logger, Logging.Info - 1, Ribasim, nothing, "message") # progress bar @test !Logging.shouldlog(logger, Logging.Debug, Ribasim, nothing, "message") + + Ribasim.close(logger) end end @@ -31,5 +33,43 @@ end @test Logging.shouldlog(logger, Logging.Info, Ribasim, nothing, "message") @test Logging.shouldlog(logger, Logging.Info - 1, Ribasim, nothing, "message") # progress bar @test Logging.shouldlog(logger, Logging.Debug, Ribasim, nothing, "message") + + Ribasim.close(logger) + end +end + +@testitem "setup_logger creates TeeLogger with 2 sinks" begin + using Logging + using LoggingExtras + mktempdir() do dir + cp( + normpath(@__DIR__, "data", "logging_test_loglevel_debug.toml"), + normpath(dir, "ribasim.toml"); + force = true, + ) + config = Ribasim.Config(normpath(dir, "ribasim.toml")) + mkdir(Ribasim.results_path(config, ".")) + logger = Ribasim.setup_logger( + config; + module_filter_function = log::Ribasim.LogMessageType -> + log._module == @__MODULE__, + ) + + with_logger(logger) do + @info "foo" + @warn "bar" + @debug "baz" + end + + Ribasim.close(logger) + + println(@__MODULE__) + + open(normpath(dir, "results", "ribasim.log"), "r") do io + result = read(io, String) + @test occursin("Info: foo", result) + @test occursin("Warning: bar", result) + @test occursin("Debug: baz", result) + end end end