Merge pull request #17 from ait-energy/dev

Fixes: bug in custom objectives; Changes: tries to catch exceptions in file handling of loggers

src/IESopt.jl

@@ -562,17 +562,21 @@ function _optimize!(model::JuMP.Model; kwargs...)
     # Logging solver output.
     if _iesopt_config(model).optimization.solver.log
         # todo: replace this with a more general approach
-        log_file = abspath(_iesopt_config(model).paths.results, "$(_iesopt_config(model).names.scenario).solverlog")
-        rm(log_file; force=true)
-        if JuMP.solver_name(model) == "Gurobi"
-            @info "Logging solver output" log_file
-            JuMP.set_attribute(model, "LogFile", log_file)
-        elseif JuMP.solver_name(model) == "HiGHS"
-            @info "Logging solver output" log_file
-            JuMP.set_attribute(model, "log_file", log_file)
-        else
-            # todo: support MOA here
-            @error "Logging solver output is currently only supported for Gurobi and HiGHS"
+        try
+            log_file = abspath(_iesopt_config(model).paths.results, "$(_iesopt_config(model).names.scenario).solverlog")
+            rm(log_file; force=true)
+            if JuMP.solver_name(model) == "Gurobi"
+                @info "Logging solver output" log_file
+                JuMP.set_attribute(model, "LogFile", log_file)
+            elseif JuMP.solver_name(model) == "HiGHS"
+                @info "Logging solver output" log_file
+                JuMP.set_attribute(model, "log_file", log_file)
+            else
+                # todo: support MOA here
+                @error "Logging solver output is currently only supported for Gurobi and HiGHS"
+            end
+        catch
+            @error "Failed to setup solver log file"
         end
     end
 

src/parser.jl

@@ -54,8 +54,11 @@ function _parse_model!(model::JuMP.Model, filename::String, global_parameters::D
 
         # Construct the objectives container & add all registered objectives.
         for (name, terms) in _iesopt_config(model).optimization.objective.functions
-            _iesopt(model).model.objectives[name] =
-                (terms=Set{JuMP.AffExpr}(), expr=JuMP.AffExpr(0.0), constants=Vector{Float64}())
+            _iesopt(model).model.objectives[name] = (
+                terms=Set{Union{JuMP.AffExpr, JuMP.VariableRef}}(),
+                expr=JuMP.AffExpr(0.0),
+                constants=Vector{Float64}(),
+            )
             _iesopt(model).aux._obj_terms[name] = terms
         end
 

src/utils/logging.jl

@@ -14,6 +14,26 @@ Logging.shouldlog(filelogger::FileLogger, arg...) = true
 Logging.min_enabled_level(filelogger::FileLogger) = Logging.Info
 Logging.catch_exceptions(filelogger::FileLogger) = Logging.catch_exceptions(filelogger.logger)
 
+function save_close_filelogger(model::JuMP.Model)
+    try
+        if _iesopt(model).logger isa LoggingExtras.TeeLogger
+            tl = _iesopt(model).logger
+            if length(tl.loggers) == 2
+                if tl.loggers[2] isa IESopt.FileLogger
+                    if isopen(tl.loggers[2].logger.stream)
+                        @info "Savely closing the file logger's iostream"
+                        close(tl.loggers[2].logger.stream)
+                    end
+                end
+            end
+        end
+    catch
+        # TODO: maybe we can do something here?
+    end
+
+    return nothing
+end
+
 function _attach_logger!(model::JuMP.Model)
     verbosity = _iesopt_config(model).verbosity
 
@@ -36,7 +56,16 @@ function _attach_logger!(model::JuMP.Model)
     else
         log_file = "$(_iesopt_config(model).names.scenario).log"
         log_path = normpath(mkpath(_iesopt_config(model).paths.results), log_file)
-        _iesopt(model).logger = LoggingExtras.TeeLogger(logger, FileLogger(log_path))
+        try
+            _iesopt(model).logger = LoggingExtras.TeeLogger(logger, FileLogger(log_path))
+        catch
+            @error (
+                "Could not create file logger, falling back to console logger only; if this happened after a " *
+                "previous model run, consider calling `save_close_filelogger(model)` after you are done with your " *
+                "previous model - before re-generating a new one - to properly release the log file handle"
+            )
+            _iesopt(model).logger = logger
+        end
     end
 end
 

test/src/basic.jl

@@ -31,11 +31,13 @@ end
             model = JuMP.Model()
             IESopt.generate!(model, joinpath(PATH_TESTFILES, "filesystem", fn); verbosity=false)
             @test haskey(model.ext[:iesopt].input.noncore[:templates], "TestComp")
+            IESopt.save_close_filelogger(model)
 
             # relative path
             cd(PATH_TESTFILES)
             model = JuMP.Model()
             IESopt.generate!(model, joinpath("filesystem", fn); verbosity=false)
+            IESopt.save_close_filelogger(model)
 
             # filename only
             @test haskey(model.ext[:iesopt].input.noncore[:templates], "TestComp")
@@ -44,6 +46,7 @@ end
             IESopt.generate!(model, fn; verbosity=false)
             @test haskey(model.ext[:iesopt].input.noncore[:templates], "TestComp")
             cd(PATH_CURRENT)
+            IESopt.save_close_filelogger(model)
         end
     end
 end

test/src/examples.jl

@@ -3,6 +3,7 @@ function _test_example_default_solver(filename::String; obj::Float64, verbosity:
         model = @suppress generate!(joinpath(PATH_EXAMPLES, filename); verbosity=verbosity, kwargs...)
         @suppress optimize!(model)
         @test JuMP.objective_value(model) ≈ obj atol = 0.1
+        IESopt.save_close_filelogger(model)
     end
 end
 
@@ -38,6 +39,7 @@ _test_example_default_solver("44_lossy_connections.iesopt.yaml"; obj=1233.75)
     optimize!(model)
     @test JuMP.value(model.ext[:iesopt].model.objectives["total_cost"].expr) ≈ 2975.0 atol = 0.05
     @test sum(JuMP.value.(values(model.ext[:iesopt].aux.constraint_safety_expressions))) ≈ 1
+    IESopt.save_close_filelogger(model)
 end
 
 # NOTE: This example fails because it tries to read two snapshots from a CSV file containing only one row.
@@ -62,6 +64,7 @@ end
         JuMP.value.(component(model, "create_gas").exp.value) .==
         [9.375, 18.75, 22.5, 25.0, 25.0, 25.0, 12.5, 15.0, 25.0],
     )
+    IESopt.save_close_filelogger(model)
 end
 
 # model = JuMP.direct_model(HiGHS.Optimizer())
@@ -76,6 +79,7 @@ end
     @test all(JuMP.value.(component(model, "buy").exp.value) .≈ [10.0, 6.0, 6.0, 0.0, 7.0, 4.0])
     obj_val_example_22 = JuMP.objective_value(model)
     _test_example_default_solver("23_snapshots_from_csv.iesopt.yaml"; obj=obj_val_example_22)
+    IESopt.save_close_filelogger(model)
 end
 
 # model = generate!(joinpath(dir, "24_linearized_optimal_powerflow.iesopt.yaml"); verbosity=false)
@@ -106,6 +110,7 @@ end
     @test JuMP.objective_value(model) ≈ -10.0
     @test JuMP.value.(IESopt.component(model, "buy_id").exp.value) == [1, 0, 1, 0]
     @test JuMP.value.(IESopt.component(model, "sell_id").exp.value) == [0, 1, 0, 1]
+    IESopt.save_close_filelogger(model)
 end
 
 # Disabled, because Benders needs to modify Decisions (which is currently not possible due to immutability).
@@ -129,6 +134,7 @@ end
     @test JuMP.objective_value(model) ≈ 44376.75 atol = 0.01
     @test sum(IESopt.extract_result(model, "plant_gas", "in:gas"; mode="value")) ≈ 986.15 atol = 0.01
     @test sum(IESopt.extract_result(model, "electrolysis", "in:electricity"; mode="value")) ≈ 758.58 atol = 0.01
+    IESopt.save_close_filelogger(model)
 end
 
 @testset "47_disable_components" begin
@@ -155,6 +161,11 @@ end
     @test JuMP.objective_value(model_coupled) <=
           JuMP.objective_value(model_AT_DE) + JuMP.objective_value(model_CH) <=
           JuMP.objective_value(model_individual)
+
+    IESopt.save_close_filelogger(model_coupled)
+    IESopt.save_close_filelogger(model_individual)
+    IESopt.save_close_filelogger(model_AT_DE)
+    IESopt.save_close_filelogger(model_CH)
 end
 
 # Clean up output files after testing is done.