From 338aeaa8f3681b8e6954dca4a4ce3dd26505e72e Mon Sep 17 00:00:00 2001 From: Alinson S Xavier Date: Fri, 31 Jul 2020 20:42:38 -0500 Subject: [PATCH] Use same logging format in Python and Julia --- src/julia/Project.toml | 2 ++ src/julia/src/MIPLearn.jl | 23 ++++++------ src/julia/src/jump_solver.jl | 1 - src/julia/src/log.jl | 62 +++++++++++++++++++++++++++++++++ src/julia/test/runtests.jl | 5 ++- src/python/miplearn/__init__.py | 2 ++ src/python/miplearn/log.py | 37 ++++++++++++++++++++ 7 files changed, 118 insertions(+), 14 deletions(-) create mode 100644 src/julia/src/log.jl create mode 100644 src/python/miplearn/log.py diff --git a/src/julia/Project.toml b/src/julia/Project.toml index 1db2064..f518e94 100644 --- a/src/julia/Project.toml +++ b/src/julia/Project.toml @@ -8,8 +8,10 @@ CPLEX = "a076750e-1247-5638-91d2-ce28b192dca0" CPLEXW = "cfecb002-79c2-11e9-35be-cb59aa640f85" Gurobi = "2e9cd046-0924-5485-92f1-d5272153d98b" JuMP = "4076af6c-e467-56ae-b986-b466b2749572" +Logging = "56ddb016-857b-54e1-b83d-db4d58db5568" MathOptInterface = "b8f27783-ece8-5eb3-8dc8-9495eed66fee" PackageCompiler = "9b87118b-4619-50d2-8e1e-99f35a4d4d9d" +Printf = "de0858da-6303-5e67-8744-51eddeeeb8d7" PyCall = "438e738f-606a-5dbb-bf0a-cddfbfd45ab0" Revise = "295af30f-e4ad-537b-8983-00126c2a3abe" Test = "8dfed614-e22c-5e08-85e1-65c5234f0b40" diff --git a/src/julia/src/MIPLearn.jl b/src/julia/src/MIPLearn.jl index a9e5a78..70f2a30 100644 --- a/src/julia/src/MIPLearn.jl +++ b/src/julia/src/MIPLearn.jl @@ -4,15 +4,18 @@ __precompile__(false) module MIPLearn - using PyCall - miplearn = pyimport("miplearn") - Instance = miplearn.Instance - LearningSolver = miplearn.LearningSolver - InternalSolver = miplearn.solvers.internal.InternalSolver - BenchmarkRunner = miplearn.BenchmarkRunner - include("jump_solver.jl") - include("knapsack.jl") +using PyCall +miplearn = pyimport("miplearn") +Instance = miplearn.Instance +LearningSolver = miplearn.LearningSolver +InternalSolver = miplearn.solvers.internal.InternalSolver +BenchmarkRunner = miplearn.BenchmarkRunner - export Instance, LearningSolver, InternalSolver, JuMPSolver, BenchmarkRunner -end +include("jump_solver.jl") +include("knapsack.jl") +include("log.jl") + +export Instance, LearningSolver, InternalSolver, JuMPSolver, BenchmarkRunner + +end # module diff --git a/src/julia/src/jump_solver.jl b/src/julia/src/jump_solver.jl index c270627..c041c12 100644 --- a/src/julia/src/jump_solver.jl +++ b/src/julia/src/jump_solver.jl @@ -51,7 +51,6 @@ function optimize_and_capture_output!(model; tee::Bool=false) end return log end - JuMP.unset_silent(model) JuMP.optimize!(model) sleep(1) redirect_stdout(original_stdout) diff --git a/src/julia/src/log.jl b/src/julia/src/log.jl new file mode 100644 index 0000000..d497cd6 --- /dev/null +++ b/src/julia/src/log.jl @@ -0,0 +1,62 @@ +import Logging: min_enabled_level, shouldlog, handle_message +using Base.CoreLogging, Logging, Printf + +struct TimeLogger <: AbstractLogger + initial_time::Float64 + file::Union{Nothing, IOStream} + screen_log_level + io_log_level +end + +function TimeLogger(; + initial_time::Float64, + file::Union{Nothing, IOStream} = nothing, + screen_log_level = CoreLogging.Info, + io_log_level = CoreLogging.Info, + ) :: TimeLogger + return TimeLogger(initial_time, file, screen_log_level, io_log_level) +end + +min_enabled_level(logger::TimeLogger) = logger.io_log_level +shouldlog(logger::TimeLogger, level, _module, group, id) = true + +function handle_message(logger::TimeLogger, + level, + message, + _module, + group, + id, + filepath, + line; + kwargs...) + elapsed_time = time() - logger.initial_time + time_string = @sprintf("[%12.3f] ", elapsed_time) + + if level >= Logging.Error + color = :light_red + elseif level >= Logging.Warn + color = :light_yellow + else + color = :light_green + end + + if level >= logger.screen_log_level + printstyled(time_string, color=color) + println(message) + end + if logger.file != nothing && level >= logger.io_log_level + write(logger.file, time_string) + write(logger.file, message) + write(logger.file, "\n") + flush(logger.file) + end +end + +function setup_logger() + initial_time = time() + global_logger(TimeLogger(initial_time=initial_time)) + miplearn = pyimport("miplearn") + miplearn.setup_logger(initial_time) +end + +export TimeLogger \ No newline at end of file diff --git a/src/julia/test/runtests.jl b/src/julia/test/runtests.jl index 8c827f2..b0c9fb5 100644 --- a/src/julia/test/runtests.jl +++ b/src/julia/test/runtests.jl @@ -3,10 +3,9 @@ # Released under the modified BSD license. See COPYING.md for more details. using Test -using PyCall +using MIPLearn -logging = pyimport("logging") -logging.basicConfig(format="%(levelname)10s %(message)s", level=logging.INFO) +MIPLearn.setup_logger() @testset "MIPLearn" begin include("jump_solver_test.jl") diff --git a/src/python/miplearn/__init__.py b/src/python/miplearn/__init__.py index b5f81af..1752abb 100644 --- a/src/python/miplearn/__init__.py +++ b/src/python/miplearn/__init__.py @@ -28,3 +28,5 @@ from .solvers.pyomo.gurobi import GurobiPyomoSolver from .solvers.guroby import GurobiSolver from .solvers.internal import InternalSolver from .solvers.learning import LearningSolver + +from .log import setup_logger diff --git a/src/python/miplearn/log.py b/src/python/miplearn/log.py new file mode 100644 index 0000000..e944e42 --- /dev/null +++ b/src/python/miplearn/log.py @@ -0,0 +1,37 @@ +# MIPLearn: Extensible Framework for Learning-Enhanced Mixed-Integer Optimization +# Copyright (C) 2020, UChicago Argonne, LLC. All rights reserved. +# Released under the modified BSD license. See COPYING.md for more details. + +from datetime import timedelta +import logging +import time + +log_colors = { + "green": '\033[92m', + "yellow": '\033[93m', + "red": '\033[91m', + "reset": '\033[0m', +} + +class TimeFormatter(): + def __init__(self, start_time): + self.start_time = start_time + + def format(self, record): + if record.levelno >= logging.ERROR: + color = log_colors["red"] + elif record.levelno >= logging.WARNING: + color = log_colors["yellow"] + else: + color = log_colors["green"] + return "%s[%12.3f]%s %s" % (color, + record.created - self.start_time, + log_colors["reset"], + record.getMessage()) + +def setup_logger(start_time): + handler = logging.StreamHandler() + handler.setFormatter(TimeFormatter(start_time)) + logging.getLogger().addHandler(handler) + logging.getLogger("miplearn").setLevel(logging.INFO) + lg = logging.getLogger("miplearn")