From 4d7f5127cf98cd327d582aaab11f68f4022d6026 Mon Sep 17 00:00:00 2001
From: Daniel Vedder <daniel.vedder@idiv.de>
Date: Mon, 23 Jan 2023 17:07:06 +0100
Subject: [PATCH] Switched to using local loggers

Previously, a global logger was used, which would have given problems
on a parallel run. Also split up the `setupdatadir()` function to
improve code structure.
---
 src/Persephone.jl            |  5 ++-
 src/core/output.jl           | 61 ++++++++++++++++++------------
 src/core/simulation.jl       | 73 +++++++++++++++++++++++-------------
 src/nature/ecologicaldata.jl |  8 ++--
 src/parameters.toml          |  2 +-
 test/paramscan.toml          |  2 +-
 test/test_parameters.toml    |  2 +-
 7 files changed, 94 insertions(+), 59 deletions(-)

diff --git a/src/Persephone.jl b/src/Persephone.jl
index 8b56527..4c1341b 100644
--- a/src/Persephone.jl
+++ b/src/Persephone.jl
@@ -66,8 +66,10 @@ export
 include("core/input.jl")
 include("core/output.jl")
 include("core/landscape.jl")
+
 include("farm/farm.jl")
 include("crop/crops.jl")
+
 include("nature/nature.jl")
 include("nature/populations.jl")
 include("nature/ecologicaldata.jl")
@@ -79,6 +81,7 @@ include("nature/ecologicaldata.jl")
 #include("nature/species/skylark.jl")
 include("nature/species/wolpertinger.jl")
 include("nature/species/wyvern.jl")
-include("core/simulation.jl")
+
+include("core/simulation.jl") #this must be last
 
 end
diff --git a/src/core/output.jl b/src/core/output.jl
index 38c09f0..09f621e 100644
--- a/src/core/output.jl
+++ b/src/core/output.jl
@@ -5,20 +5,18 @@
 
 const LOGFILE = "simulation.log"
 
-## Note: `setupdatadir()` was adapted from the GeMM model by Leidinger et al.
+## Much of this code was adapted from the GeMM model by Leidinger et al.
 ## (https://github.com/CCTB-Ecomods/gemm/blob/master/src/output.jl)
 
 """
-    setupdatadir()
+    createdatadir(outdir, overwrite)
 
-Creates the output directory and copies relevant files into it.
+Creates the output directory, dealing with possible conflicts.
 """
-function setupdatadir(model::AgentBasedModel)
-    # Check whether the output directory already exists and handle conflicts
-    if isdir(@param(core.outdir))
-        overwrite = @param(core.overwrite)
-        if @param(core.overwrite) == "ask"
-            println("The chosen output directory $(@param(core.outdir)) already exists.")
+function createdatadir(outdir::String, overwrite::Union{Bool,String})
+    if isdir(outdir)
+        if overwrite == "ask"
+            println("The chosen output directory $(outdir) already exists.")
             println("Type 'yes' to overwrite this directory. Otherwise, the simulation will abort.")
             print("Overwrite? ")
             answer = readline()
@@ -27,30 +25,46 @@ function setupdatadir(model::AgentBasedModel)
         if !overwrite
             Base.error("Output directory exists, will not overwrite. Aborting.")
         else
-            @warn "Overwriting existing output directory $(@param(core.outdir))."
+            @warn "Overwriting existing output directory $(outdir)."
         end
     end
-    mkpath(@param(core.outdir))
-    # Setup the logging system and logfile
+    mkpath(outdir)
+end
+
+"""
+    modellogger(logsetting, outdir)
+
+Create a logger object that writes output both to screen and to a logfile.
+This object is stored as `model.logger` and can then be used with `with_logger()`.
+Note: requires `createdatadir()` to be run first.
+"""
+function modellogger(logsetting::String, outdir::String)
+    #XXX If this is a parallel run, should we turn off logging to screen?
     loglevel = Logging.Info
-    if @param(core.loglevel) == "debug"
+    if logsetting == "debug"
         loglevel = Logging.Debug
-    elseif @param(core.loglevel) == "quiet"
+    elseif logsetting == "warn"
         loglevel = Logging.Warn
     end
-    logfile = open(joinpath(@param(core.outdir), LOGFILE), "w+")
-    simulationlogger = TeeLogger(ConsoleLogger(logfile, loglevel),
-                                 ConsoleLogger(stdout, loglevel))
-    global_logger(simulationlogger)
+    logfile = open(joinpath(outdir, LOGFILE), "w+")
+    TeeLogger(ConsoleLogger(logfile, loglevel),
+              ConsoleLogger(stdout, loglevel))
+end
+
+"""
+    saveinputfiles(model)
+
+Copy all input files into the output directory, including the actual parameter
+settings used. This allows replicating a run in future.
+"""
+function saveinputfiles(model::AgentBasedModel)
     @debug "Setting up output directory $(@param(core.outdir))."
-    # Export a copy of the current parameter settings to the output folder.
-    # This can be used to replicate this exact run in future, and also
-    # records the current time and git commit.
     currentcommit = read(`git rev-parse HEAD`, String)[1:8]
     open(joinpath(@param(core.outdir), basename(@param(core.configfile))), "w") do f
         println(f, "#\n# --- Persephone configuration parameters ---")
         println(f, "# This file was generated automatically.")
         println(f, "# Simulation run on $(string(Dates.format(Dates.now(), "d u Y HH:MM:SS"))),")
+        # Record the current git commit and versions of dependencies for reproducibility
         println(f, "# with Persephone $(pkgversion(Persephone)), git commit $(currentcommit),")
         println(f, "# running on Julia $(VERSION) with Agents.jl $(pkgversion(Agents)).\n#\n")
         if !isempty(strip(read(`git status -s`, String)))
@@ -68,7 +82,6 @@ function setupdatadir(model::AgentBasedModel)
     cp(ffmap, joinpath(@param(core.outdir), basename(ffmap)), force = true)
 end
 
-
 """
     expandTOML(dict)
 
@@ -111,8 +124,8 @@ end
 Create and register a new data output. This function must be called by all submodels
 that want to have their output functions called regularly.
 """
-function newdataoutput(model::AgentBasedModel, filename::String, header::String,
-                       outputfunction::Function, frequency::String)
+function newdataoutput!(model::AgentBasedModel, filename::String, header::String,
+                        outputfunction::Function, frequency::String)
     if !(frequency in ("daily", "monthly", "yearly", "end", "never"))
         Base.error("Invalid frequency '$frequency' for $filename.")
     end
diff --git a/src/core/simulation.jl b/src/core/simulation.jl
index 352640b..0195a97 100644
--- a/src/core/simulation.jl
+++ b/src/core/simulation.jl
@@ -8,33 +8,48 @@
 # run) and one for parameter scanning?
 
 """
-    initmodels(settings)
+    initmodel(settings)
 
-Initialise one or more model objects using ready-made settings dicts. This is
-a helper function for `initialise()`.
+Initialise a model object using a ready-made settings dict. This is
+a helper function for `initialise()` and `initmodelsparallel()`.
 """
-function initmodels(settingsdicts::Vector{Dict{String, Any}})
-    #TODO parallelise model initialisation
-    @debug "Initialising model object(s)."
-    # generate a set of models from these dicts
-    models = Vector{AgentBasedModel}()
-    for settings in settingsdicts
+function initmodel(settings::Dict{String, Any})
+    @debug "Initialising model object."
+    createdatadir(settings["core.outdir"], settings["core.overwrite"])
+    logger = modellogger(settings["core.loglevel"], settings["core.outdir"])
+    with_logger(logger) do
         events = Vector{FarmEvent}()
         dataoutputs = Vector{DataOutput}()
         landscape = initlandscape(settings["core.landcovermap"], settings["core.farmfieldsmap"])
         space = GridSpace(size(landscape), periodic=false)
         properties = Dict{Symbol,Any}(:settings=>settings,
+                                      :logger=>logger,
                                       :date=>settings["core.startdate"],
                                       :landscape=>landscape,
                                       :dataoutputs=>dataoutputs,
                                       :events=>events)
         model = AgentBasedModel(Union{Farmer,Animal,FarmPlot}, space, properties=properties,
                                 rng=StableRNG(settings["core.seed"]), warn=false)
-        setupdatadir(model)
+        saveinputfiles(model)
         initfarms!(model)
         initfields!(model)
         initnature!(model)
-        push!(models, model)
+        model
+    end
+end
+
+"""
+    initmodelsparallel(settings)
+
+Initialise multiple model objects using ready-made settings dicts. This is
+a helper function for `initialise()`.
+"""
+function initmodelsparallel(settingsdicts::Vector{Dict{String, Any}})
+    #TODO parallelise model initialisation
+    @debug "Beginning to initialise model objects."
+    models = Vector{AgentBasedModel}()
+    for settings in settingsdicts
+        push!(models, initmodel(settings))
     end
     models
 end
@@ -85,8 +100,7 @@ function initialise(config::String=PARAMFILE, seed::Union{Int64,Nothing}=nothing
     settings = getsettings(config, seed)
     scanparams = settings["internal.scanparams"]
     delete!(settings, "internal.scanparams")
-    models = initmodels(paramscan(settings, scanparams))
-    (length(models) == 1) ? models[1] : models
+    isempty(scanparams) ? initmodel(settings) : initmodelsparallel(settings, scanparameters)
 end
 
 """
@@ -95,18 +109,21 @@ end
 Execute one update of the model.
 """
 function stepsimulation!(model::AgentBasedModel)
-    @info "Simulating day $(model.date)."
-    for a in Schedulers.ByType((Farmer,FarmPlot,Animal), true)(model)
-        try #The animal may have been killed
-            stepagent!(model[a], model)
-        catch exc
-            # check if the KeyError comes from the `model[a]` or the function call
-            isa(exc, KeyError) && isa(exc.key, Int) ? continue : throw(exc)
+    with_logger(model.logger) do
+        @info "Simulating day $(model.date)."
+        for a in Schedulers.ByType((Farmer,FarmPlot,Animal), true)(model)
+            try #The animal may have been killed
+                stepagent!(model[a], model)
+            catch exc
+                # check if the KeyError comes from the `model[a]` or the function call
+                isa(exc, KeyError) && isa(exc.key, Int) ? continue : throw(exc)
+            end
         end
+        updateevents!(model)
+        outputdata(model)
+        model.date += Day(1)
+        model
     end
-    updateevents!(model)
-    outputdata(model)
-    model.date += Day(1)
 end
 
 """
@@ -115,10 +132,12 @@ end
 Wrap up the simulation. Currently doesn't do anything except print some information.
 """
 function finalise!(model::AgentBasedModel)
-    @info "Simulated $(model.date-@param(core.startdate))."
-    @info "Simulation run completed at $(Dates.now()),\nwrote output to $(@param(core.outdir))."
-    #XXX is there anything to do here?
-    model
+    with_logger(model.logger) do
+        @info "Simulated $(model.date-@param(core.startdate))."
+        @info "Simulation run completed at $(Dates.now()),\nwrote output to $(@param(core.outdir))."
+        #XXX is there anything to do here?
+        model
+    end
 end
 
 """
diff --git a/src/nature/ecologicaldata.jl b/src/nature/ecologicaldata.jl
index aa21296..2573252 100644
--- a/src/nature/ecologicaldata.jl
+++ b/src/nature/ecologicaldata.jl
@@ -12,10 +12,10 @@ const INDFILE = "individuals.csv"
 Create output files for each data group collected by the nature model.
 """
 function initecologicaldata(model::AgentBasedModel)
-    newdataoutput(model, POPFILE, "Date;Species;Abundance",
-                  savepopulationdata, @param(nature.popoutfreq))
-    newdataoutput(model, INDFILE, "Date;ID;X;Y;Species;Sex;Age",
-                  saveindividualdata, @param(nature.indoutfreq))
+    newdataoutput!(model, POPFILE, "Date;Species;Abundance",
+                   savepopulationdata, @param(nature.popoutfreq))
+    newdataoutput!(model, INDFILE, "Date;ID;X;Y;Species;Sex;Age",
+                   saveindividualdata, @param(nature.indoutfreq))
 end
 
 """
diff --git a/src/parameters.toml b/src/parameters.toml
index 9f8f8e0..e3359e3 100644
--- a/src/parameters.toml
+++ b/src/parameters.toml
@@ -12,7 +12,7 @@ landcovermap = "data/landcover_jena.tif" # location of the landcover map
 farmfieldsmap = "data/fields_jena.tif" # location of the field geometry map
 outdir = "results" # location and name of the output folder
 overwrite = "ask" # overwrite the output directory? (true/false/"ask")
-loglevel = "debug" # verbosity level: "debug", "info", "quiet"
+loglevel = "debug" # verbosity level: "debug", "info", "warn"
 seed = 2 # seed value for the RNG (0 -> random value)
 # dates to start and end the simulation
 startdate = 2022-01-01
diff --git a/test/paramscan.toml b/test/paramscan.toml
index d17505e..caac133 100644
--- a/test/paramscan.toml
+++ b/test/paramscan.toml
@@ -9,7 +9,7 @@ landcovermap = "landcover_jena.tif" # location of the landcover map
 farmfieldsmap = "fields_jena.tif" # location of the field geometry map
 outdir = "results_test_paramscan" # location and name of the output folder
 overwrite = ["ask",true] # overwrite the output directory? (true/false/"ask")
-loglevel = ["debug", "info"] # verbosity level: "debug", "info", "quiet"
+loglevel = ["debug", "info"] # verbosity level: "debug", "info", "warn"
 seed = [1,2,3] # seed value for the RNG (0 -> random value)
 # dates to start and end the simulation
 startdate = 2022-01-01
diff --git a/test/test_parameters.toml b/test/test_parameters.toml
index 3e5e046..8692eba 100644
--- a/test/test_parameters.toml
+++ b/test/test_parameters.toml
@@ -9,7 +9,7 @@ landcovermap = "landcover_jena.tif" # location of the landcover map
 farmfieldsmap = "fields_jena.tif" # location of the field geometry map
 outdir = "results_testsuite" # location and name of the output folder
 overwrite = true # overwrite the output directory? (true/false/"ask")
-loglevel = "quiet" # verbosity level: "debug", "info", "quiet"
+loglevel = "warn" # verbosity level: "debug", "info", "warn"
 seed = 1 # seed value for the RNG (0 -> random value)
 # dates to start and end the simulation
 startdate = 2022-02-01
-- 
GitLab