Skip to content
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ InfrastructureModels.jl Change Log

### Staged
- Various maintenance updates to bring InfrastructureModels up to date (#97)
- Remove Memento and switch to Logging.jl (#99)

### v0.7.8
- Fix support for strongly typed network data (#92)
Expand Down
6 changes: 3 additions & 3 deletions Project.toml
Original file line number Diff line number Diff line change
@@ -1,20 +1,20 @@
name = "InfrastructureModels"
uuid = "2030c09a-7f63-5d83-885d-db604e0e9cc0"
version = "0.7.8"
authors = ["Carleton Coffrin"]
repo = "https://github.com/lanl-ansi/InfrastructureModels.jl"
version = "0.7.8"

[deps]
JuMP = "4076af6c-e467-56ae-b986-b466b2749572"
Memento = "f28f55f0-a522-5efc-85c2-fe41dfb9b2d9"
Logging = "56ddb016-857b-54e1-b83d-db4d58db5568"

[compat]
ECOS = "1"
Ipopt = "1"
JSON = "0.21, 1"
JuMP = "1"
Juniper = "0.8, 0.9"
Memento = "1"
Logging = "1.10"
julia = "1.10"

[extras]
Expand Down
22 changes: 5 additions & 17 deletions src/InfrastructureModels.jl
Original file line number Diff line number Diff line change
@@ -1,28 +1,16 @@
module InfrastructureModels

import JuMP
import Memento
import Logging

# Create our module level logger (this will get precompiled)
const _LOGGER = Memento.getlogger(@__MODULE__)

# Register the module level logger at runtime so that folks can access the logger via `getlogger(InfrastructureModels)`
# NOTE: If this line is not included then the precompiled `Infrastructure.LOGGER` won't be registered at runtime.
__init__() = Memento.register(_LOGGER)

"Suppresses information and warning messages output by InfrastructureModels, for fine grained control use the Memento package"
function silence()
Memento.info(_LOGGER, "Suppressing information and warning messages for the rest of this session. Use the Memento package for more fine-grained control of logging.")
Memento.setlevel!(_LOGGER, "error")
end

"alows the user to set the logging level without the need to add Memento"
function logger_config!(level; kwargs...)
Memento.config!(_LOGGER, level, kwargs...)
function __init__()
logger_config!("info")

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as Memento.register, we need to enable the logger on __init__.

return
end

const nw_id_default = 0

include("core/logging.jl")
include("core/base.jl")
include("core/data.jl")
include("core/constraint.jl")
Expand Down
32 changes: 16 additions & 16 deletions src/core/base.jl
Original file line number Diff line number Diff line change
Expand Up @@ -190,7 +190,7 @@ function _populate_ref_it!(refs::Dict{Symbol, <:Any}, data_it::Dict{String, <:An
# Build a multinetwork representation of the data.
if ismultinetwork(data_it)
nws_data = data_it["nw"]

for (key, item) in data_it
if key != "nw"
refs[:it][Symbol(it)][Symbol(key)] = item
Expand All @@ -206,7 +206,7 @@ function _populate_ref_it!(refs::Dict{Symbol, <:Any}, data_it::Dict{String, <:An
for (n, nw_data) in nws_data
nw_id = parse(Int, n)
ref = nws[nw_id] = Dict{Symbol, Any}()

for (key, item) in nw_data
if !(key in global_keys)
if typeof(item) <: Dict{String, <:Any} && _iscomponentdict(item)
Expand Down Expand Up @@ -322,12 +322,12 @@ end
function instantiate_model(
data::Dict{String,<:Any}, model_type::Type, build_method, ref_add_core!,
global_keys::Set{String}; ref_extensions=[], kwargs...)
# NOTE, this model constructor will build the ref dict using the latest info from the data
# NOTE, this model constructor will build the ref dict using the latest info from the data
start_time = time()

imo = InitializeInfrastructureModel(model_type, data, global_keys; kwargs...)

Memento.debug(_LOGGER, "initialize model time: $(time() - start_time)")
@_debug("initialize model time: $(time() - start_time)")

start_time = time()
ref_add_core!(imo.ref)
Expand All @@ -336,11 +336,11 @@ function instantiate_model(
ref_ext!(imo.ref, imo.data)
end

Memento.debug(_LOGGER, "build ref time: $(time() - start_time)")
@_debug("build ref time: $(time() - start_time)")

start_time = time()
build_method(imo)
Memento.debug(_LOGGER, "build method time: $(time() - start_time)")
@_debug("build method time: $(time() - start_time)")

return imo
end
Expand All @@ -350,12 +350,12 @@ end
function instantiate_model(
data::Dict{String,<:Any}, model_type::Type, build_method, ref_add_core!,
global_keys::Set{String}, it::Symbol; ref_extensions=[], kwargs...)
# NOTE, this model constructor will build the ref dict using the latest info from the data
# NOTE, this model constructor will build the ref dict using the latest info from the data
start_time = time()

imo = InitializeInfrastructureModel(model_type, data, global_keys, it; kwargs...)

Memento.debug(_LOGGER, "initialize model time: $(time() - start_time)")
@_debug("initialize model time: $(time() - start_time)")

start_time = time()
ref_add_core!(imo.ref)
Expand All @@ -364,11 +364,11 @@ function instantiate_model(
ref_ext!(imo.ref, imo.data)
end

Memento.debug(_LOGGER, "build ref time: $(time() - start_time)")
@_debug("build ref time: $(time() - start_time)")

start_time = time()
build_method(imo)
Memento.debug(_LOGGER, "build method time: $(time() - start_time)")
@_debug("build method time: $(time() - start_time)")

return imo
end
Expand All @@ -386,27 +386,27 @@ function optimize_model!(aim::AbstractInfrastructureModel; relax_integrality=fal
if JuMP.backend(aim.model).optimizer === nothing
JuMP.set_optimizer(aim.model, optimizer)
else
Memento.warn(_LOGGER, "Model already contains optimizer, cannot use optimizer specified in `optimize_model!`")
@_warn("Model already contains optimizer, cannot use optimizer specified in `optimize_model!`")
end
end

if JuMP.mode(aim.model) != JuMP.DIRECT && JuMP.backend(aim.model).optimizer === nothing
Memento.error(_LOGGER, "No optimizer specified in `optimize_model!` or the given JuMP model.")
@_error("No optimizer specified in `optimize_model!` or the given JuMP model.")
end

_, solve_time, solve_bytes_alloc, sec_in_gc = @timed JuMP.optimize!(aim.model)

try
solve_time = JuMP.solve_time(aim.model)
catch
Memento.warn(_LOGGER, "The given optimizer does not provide the SolveTime() attribute, falling back on @timed. This is not a rigorous timing value.");
@_warn("The given optimizer does not provide the SolveTime() attribute, falling back on @timed. This is not a rigorous timing value.");
end
Memento.debug(_LOGGER, "JuMP model optimize time: $(time() - start_time)")

@_debug("JuMP model optimize time: $(time() - start_time)")

start_time = time()
result = build_result(aim, solve_time; solution_processors=solution_processors)
Memento.debug(_LOGGER, "solution build time: $(time() - start_time)")
@_debug("solution build time: $(time() - start_time)")

aim.solution = result["solution"]

Expand Down
40 changes: 20 additions & 20 deletions src/core/data.jl
Original file line number Diff line number Diff line change
Expand Up @@ -2,10 +2,10 @@
function update_data!(data::Dict{String,<:Any}, new_data::Dict{String,<:Any})
if haskey(data, "per_unit") && haskey(new_data, "per_unit")
if data["per_unit"] != new_data["per_unit"]
Memento.error(_LOGGER, "update_data requires datasets in the same units, try make_per_unit and make_mixed_units")
@_error("update_data requires datasets in the same units, try make_per_unit and make_mixed_units")
end
else
Memento.warn(_LOGGER, "running update_data with data that does not include per_unit field, units may be incorrect")
@_warn("running update_data with data that does not include per_unit field, units may be incorrect")
end

_update_data!(data, new_data)
Expand Down Expand Up @@ -101,7 +101,7 @@ end
function replicate(sn_data::Dict{String,<:Any}, count::Int, global_keys::Set{String})
@assert count > 0
if ismultinetwork(sn_data)
Memento.error(_LOGGER, "replicate can only be used on single networks")
@_error("replicate can only be used on single networks")
end

name = get(sn_data, "name", "anonymous")
Expand Down Expand Up @@ -137,17 +137,17 @@ function make_multinetwork(data::Dict{String, <:Any}, it::String, global_keys::S
data_it = ismultiinfrastructure(data) ? data["it"][it] : data

if InfrastructureModels.ismultinetwork(data_it)
Memento.error(_LOGGER, "make_multinetwork does not support multinetwork data")
@_error("make_multinetwork does not support multinetwork data")
end

if !haskey(data_it, "time_series")
Memento.error(_LOGGER, "make_multinetwork requires time_series data")
@_error("make_multinetwork requires time_series data")
end

steps = data_it["time_series"]["num_steps"]

if !isa(steps, Int)
Memento.error(_LOGGER, "the value of num_steps should be an integer, given $(steps)")
@_error("the value of num_steps should be an integer, given $(steps)")
end

mn_data = replicate(data_it, steps, union(global_keys, Set(["time_series"])))
Expand All @@ -161,16 +161,16 @@ function make_multinetwork(data::Dict{String, <:Any}, it::String, global_keys::S
if isa(v, Dict) && haskey(nw_data, k)
#println(k); println(v)
_update_data_timepoint!(nw_data[k], v, i)
elseif isa(v, Array)
if length(v) != steps
Memento.error(_LOGGER, "the size of the array $k in the time series block must be equal to $steps, currently it is $(length(v))")
else
elseif isa(v, Array)
if length(v) != steps
@_error("the size of the array $k in the time series block must be equal to $steps, currently it is $(length(v))")
else
#println(k); println(v[i])
nw_data[k] = v[i]
end
end
else
mn_data[k] = v
end
end
end
end

Expand All @@ -183,15 +183,15 @@ end
"loads a single time point from a time_series data block into the current network"
function load_timepoint!(data::Dict{String, <:Any}, step_index::Int)
if InfrastructureModels.ismultinetwork(data)
Memento.error(_LOGGER, "load_timepoint! does not support multinetwork data")
@_error("load_timepoint! does not support multinetwork data")
end

if !haskey(data, "time_series")
Memento.error(_LOGGER, "load_timepoint! requires time_series data")
@_error("load_timepoint! requires time_series data")
end

if step_index < 1 || step_index > data["time_series"]["num_steps"]
Memento.error(_LOGGER, "a step index of $(step_index) is outside the valid range of 1:$(data["time_series"]["num_steps"])")
@_error("a step index of $(step_index) is outside the valid range of 1:$(data["time_series"]["num_steps"])")
end

for (k,v) in data["time_series"]
Expand All @@ -215,10 +215,10 @@ function _update_data_timepoint!(data::Dict{String, <:Any}, new_data::Dict{Strin
elseif (!isa(v, Dict) || !isa(v, Array)) && isa(new_v, Array)
data[key] = new_v[step]
else
Memento.warn(_LOGGER, "skipping key $(key) because object types do not match, target $(typeof(v)) source $(typeof(new_v))")
@_warn("skipping key $(key) because object types do not match, target $(typeof(v)) source $(typeof(new_v))")
end
else
Memento.warn(_LOGGER, "skipping time_series key $(key) because it does not occur in the target data")
@_warn("skipping time_series key $(key) because it does not occur in the target data")
end
end
end
Expand All @@ -239,7 +239,7 @@ component_table(data::Dict{String,<:Any}, component::String, field::String) = co
function _component_table(data::Dict{String,<:Any}, component::String, fields::Vector{String})
comps = data[component]
if !_iscomponentdict(comps)
Memento.error(_LOGGER, "$(component) does not appear to refer to a component list")
@_error("$(component) does not appear to refer to a component list")
end

items = []
Expand Down Expand Up @@ -277,7 +277,7 @@ function summary(io::IO, data::Dict{String,<:Any};
)

if ismultinetwork(data)
Memento.error(_LOGGER, "summary does not yet support multinetwork data")
@_error("summary does not yet support multinetwork data")
end

component_types = []
Expand All @@ -298,7 +298,7 @@ function summary(io::IO, data::Dict{String,<:Any};
println(io, "")
println(io, _bold("Table Counts"))
end

for k in sort(component_types, by=x->get(component_types_order, x, max_parameter_value))
println(io, " $(k): $(length(data[k]))")
end
Expand Down
56 changes: 56 additions & 0 deletions src/core/logging.jl
Original file line number Diff line number Diff line change
@@ -0,0 +1,56 @@
const _LOGGER = Ref{Logging.ConsoleLogger}()

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the main file for the logging.

The _LOGGER is a const but it is a Ref because Logging.ConsoleLogger is immutable; we want to be able to change the logging level at runtime.


"""
silence()

Silence logging within InfrastructureModels.

This is equivalent to calling `logger_config!("error")`.
"""
silence() = logger_config!("error")

function _meta_formatter(level::Logging.LogLevel, _module, args...)
return Logging.default_logcolor(level), "$(_module) | $level]:", ""

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here is where we can change how the log messages are formatted. For now, it just prefaces the log message with something like [InfrastructureModels | Warn]: msg. (Note that the opening [ is added automatically by Logging.jl.)

In future we could add more information like file and line number. Or we could standardise this function into InfrastructureModels.meta_formatter so that other InfrastructureModels packages could all use the same formatting. For now, we're just copying this function into each package.

end

function logger_config!(level::Logging.LogLevel)
_LOGGER[] =
Logging.ConsoleLogger(stdout, level; meta_formatter = _meta_formatter)

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This function updates the global _LOGGER.

return
end

"""
logger_config!(level::String)

Set the logging level within PowerModels. `level` must be one of `"error"`,
`"warn"`, `"info"`, or `"debug"`.
"""
function logger_config!(level::String)
return getfield(Logging, level |> titlecase |> Symbol) |> logger_config!

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a bit messy. The other option is a big if level == "error" ... end.

If you miss-type, you get this error:

julia> getfield(Logging, "err" |> titlecase |> Symbol)
ERROR: UndefVarError: `Err` not defined in `Logging`
Suggestion: check for spelling errors or missing imports.

end

function _log_if_level(f, level, logger = _LOGGER[])
if level >= Logging.min_enabled_level(logger)
Logging.with_logger(f, logger)

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The if level >= ... check is a cheap check to see if the logger should run. If we shouldn't log this message, then we can skip with_logger entirely (it has some overhead and allocations).

end
return
end

macro _error(msg)
return quote
$_log_if_level(() -> @error($msg), $(Logging.Error))
error($msg)

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note that @error doesn't throw. But Memento.error did. To preserve backwards compatibility we add an explicit error(msg) here.

end |> esc
end

macro _warn(msg)
return :($_log_if_level(() -> @warn($msg), $(Logging.Warn)) )|> esc
end

macro _debug(msg)
return :($_log_if_level(() -> @debug($msg), $(Logging.Debug))) |> esc
end

macro _info(msg)
return :($_log_if_level(() -> @info($msg), $(Logging.Info)) )|> esc
end
6 changes: 3 additions & 3 deletions src/core/solution.jl
Original file line number Diff line number Diff line change
Expand Up @@ -5,15 +5,15 @@ function build_result(aim::AbstractInfrastructureModel, solve_time; solution_pro
try
result_count = JuMP.result_count(aim.model)
catch
Memento.warn(_LOGGER, "the given optimizer does not provide the ResultCount() attribute, assuming the solver returned a solution which may be incorrect.");
@_warn("the given optimizer does not provide the ResultCount() attribute, assuming the solver returned a solution which may be incorrect.");
end

solution = Dict{String,Any}()

if result_count > 0
solution = build_solution(aim, post_processors=solution_processors)
else
Memento.warn(_LOGGER, "model has no results, solution cannot be built")
@_warn("model has no results, solution cannot be built")
end

result = Dict{String,Any}(
Expand Down Expand Up @@ -166,7 +166,7 @@ end

""
function build_solution_values(var::Any)
Memento.warn(_LOGGER, "build_solution_values found unknown type $(typeof(var))")
@_warn("build_solution_values found unknown type $(typeof(var))")
return var
end

Expand Down
2 changes: 1 addition & 1 deletion src/io/common.jl
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ function arrays_to_dicts!(data::Dict{String,<:Any})
if !(haskey(dict, key))
dict[key] = item
else
Memento.warn(_LOGGER, "skipping component $(item["index"]) from the $(k) table because a component with the same id already exists")
@_warn("skipping component $(item["index"]) from the $(k) table because a component with the same id already exists")
end
end
data[k] = dict
Expand Down
Loading
Loading