Skip to content

Commit

Permalink
print low level logs (#719)
Browse files Browse the repository at this point in the history
see review and history in #723

---------

Co-authored-by: Thomas Bittar <[email protected]>
  • Loading branch information
a-zakir and tbittar authored Jan 4, 2024
1 parent 7735ca1 commit 32c263b
Show file tree
Hide file tree
Showing 42 changed files with 1,012 additions and 129 deletions.
2 changes: 1 addition & 1 deletion cmake/dependencies/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ if (NOT antares-solver_FOUND)

set(REPOSITORY "https://github.com/AntaresSimulatorTeam/Antares_Simulator.git")
set(TAG "v${ANTARES_VERSION_TAG}")
set(CMAKE_ARGS "-DBUILD_UI=OFF -DCMAKE_TOOLCHAIN_FILE=${CMAKE_TOOLCHAIN_FILE} -DDEPS_INSTALL_DIR=${DEPS_INSTALL_DIR} -DBUILD_not_system=OFF -DBUILD_ortools=ON")
set(CMAKE_ARGS "-DBUILD_UI=OFF -DCMAKE_TOOLCHAIN_FILE=${CMAKE_TOOLCHAIN_FILE} -DDEPS_INSTALL_DIR=${DEPS_INSTALL_DIR} -DBUILD_not_system=OFF -DBUILD_ortools=ON -DCMAKE_PREFIX_PATH=${DEPS_INSTALL_DIR}/../antares-xpansion/vcpkg_installed")

if (CMAKE_BUILD_TYPE STREQUAL "Debug")
set(ANTARES_BUILD_TYPE "debug")
Expand Down
18 changes: 13 additions & 5 deletions docs/user-guide/get-started/settings-definition.md
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ The following section lists the configurable parameters. If the user does not sp
|[`master`](#master) | `integer` | Resolution mode of the master problem |
|[`yearly-weights`](#yearly-weights) | `None` | Path of the Monte-Carlo weights file |
|[`solver`](#solver) | `Cbc` | Name of the solver |
|[`log_level`](#log_level) | `0` | Solver's log level |
|[`log_level`](#log_level) | `0` | Logs severity |
|[`additional-constraints`](#additional-constraints) | `None` | Path of the additional constraints file |
|[`separation_parameter`](#separation_parameter) | `0.5` | Step size for the in-out separation |
|[`relaxed_optimality_gap`](#relaxed_optimality_gap) | `1e-5` | Threshold to switch from relaxed to integer master |
Expand Down Expand Up @@ -205,13 +205,21 @@ To use another solver, you have to build the package with the chosen solver, ple

### `log_level`

Positive integer, specifying the `solver`'s log severity. Default value: `0`.
Possible values :`{0, 1, 2}`, specifying the `solver`'s log severity. Default value: `0`.

For now two log levels are available:
Logs can be printed both in the console and in a file. There are 3 types of logs:

- If `log_level = 0`: basic solver logs are printed.
- **Operational**: Displays progress information for the investment on candidates and costs,
- **Benders**: Displays information on the progress of the Benders algorithm,
- **Solver**: Logs of the solver called for the resolution of each master or subproblem.

The table below details the behavior depending on the `log_level`.

| | **Operational** | **Benders** | **Solver**
|-------------|------------------------------|-------------|------------
| **File** | Always `(reportbenders.txt)` | Always `(benders_solver.log)` | 2 `(solver_log_proc_<proc_num>.txt)`
| **Console** | 0 | >= 1 | Never

- If `log_level > 0`: full logs are printed simultaneously in standard output and in `benders.log` file located in the `lp` folder.

### `additional-constraints`

Expand Down
33 changes: 21 additions & 12 deletions src/cpp/benders/benders_by_batch/BendersByBatch.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -8,10 +8,11 @@
#include "BatchCollection.h"
#include "RandomBatchShuffler.h"
#include "glog/logging.h"
BendersByBatch::BendersByBatch(BendersBaseOptions const &options, Logger logger,
Writer writer, mpi::environment &env,
mpi::communicator &world)
: BendersMpi(options, logger, writer, env, world) {}
BendersByBatch::BendersByBatch(
BendersBaseOptions const &options, Logger logger, Writer writer,
mpi::environment &env, mpi::communicator &world,
std::shared_ptr<MathLoggerDriver> mathLoggerDriver)
: BendersMpi(options, logger, writer, env, world, mathLoggerDriver) {}

void BendersByBatch::InitializeProblems() {
MatchProblemToId();
Expand Down Expand Up @@ -75,8 +76,8 @@ void BendersByBatch::MasterLoop() {
random_batch_permutation_.resize(number_of_batch_);
batch_counter_ = 0;
current_batch_id_ = 0;

_data.number_of_subproblem_resolved = 0;
_data.number_of_subproblem_solved = 0;
_data.cumulative_number_of_subproblem_solved = 0;
cumulative_subproblems_timer_per_iter_ = 0;
first_unsolved_batch_ = 0;
while (!_data.stop) {
Expand Down Expand Up @@ -112,21 +113,24 @@ void BendersByBatch::MasterLoop() {
random_batch_permutation_.size(), rank_0);
SeparationLoop();
if (Rank() == rank_0) {
_data.elapsed_time = GetBendersTime();
_data.iteration_time = -_data.benders_time;
_data.benders_time = GetBendersTime();
_data.iteration_time += _data.benders_time;
_data.stop = ShouldBendersStop();
}
BroadCast(_data.stop, rank_0);
BroadCast(batch_counter_, rank_0);
SetSubproblemsCumulativeCpuTime(cumulative_subproblems_timer_per_iter_);
_logger->cumulative_number_of_sub_problem_resolved(
_data.number_of_subproblem_resolved +
GetNumOfSubProblemsResolvedBeforeResume());
_logger->cumulative_number_of_sub_problem_solved(
_data.cumulative_number_of_subproblem_solved +
GetNumOfSubProblemsSolvedBeforeResume());
_logger->LogSubproblemsSolvingCumulativeCpuTime(
GetSubproblemsCumulativeCpuTime());
_logger->LogSubproblemsSolvingWalltime(GetSubproblemsWalltime());
_logger->display_message(
"\\________________________________________________________________"
"________");
mathLoggerDriver_->Print(_data);
}
}
void BendersByBatch::SeparationLoop() {
Expand All @@ -135,13 +139,16 @@ void BendersByBatch::SeparationLoop() {
batch_counter_ = 0;
while (misprice_ && batch_counter_ < number_of_batch_) {
_data.it++;
ResetSimplexIterationsBounds();

_logger->log_at_initialization(_data.it + GetNumIterationsBeforeRestart());
ComputeXCut();
_logger->log_iteration_candidates(bendersDataToLogData(_data));
BroadcastXCut();
UpdateRemainingEpsilon();
_data.number_of_subproblem_solved = 0;
SolveBatches();

if (Rank() == rank_0) {
UpdateTrace();
SaveCurrentBendersData();
Expand Down Expand Up @@ -195,7 +202,8 @@ void BendersByBatch::SolveBatches() {
Reduce(GetSubproblemsCpuTime(), cumulative_subproblems_timer_per_iter_,
std::plus<double>(), rank_0);
if (Rank() == rank_0) {
_data.number_of_subproblem_resolved += batch_sub_problems.size();
_data.number_of_subproblem_solved += batch_sub_problems.size();
_data.cumulative_number_of_subproblem_solved += batch_sub_problems.size();
remaining_epsilon_ -= batch_subproblems_costs_contribution_in_gap;
}

Expand Down Expand Up @@ -229,6 +237,7 @@ void BendersByBatch::BuildCut(
for (const auto &subproblem_map : gathered_subproblem_map) {
for (auto &&[_, subproblem_data] : subproblem_map) {
SetSubproblemCost(GetSubproblemCost() + subproblem_data.subproblem_cost);
BoundSimplexIterations(subproblem_data.simplex_iter);
}
}
for (const auto &subproblem_map : gathered_subproblem_map) {
Expand Down Expand Up @@ -302,7 +311,7 @@ double BendersByBatch::Gap() const {
*
*/
void BendersByBatch::UpdateStoppingCriterion() {
if (_data.elapsed_time > Options().TIME_LIMIT) {
if (_data.benders_time > Options().TIME_LIMIT) {
_data.stopping_criterion = StoppingCriterion::timelimit;
} else if ((Options().MAX_ITERATIONS != -1) &&
(_data.it >= Options().MAX_ITERATIONS))
Expand Down
4 changes: 2 additions & 2 deletions src/cpp/benders/benders_by_batch/include/BendersByBatch.h
Original file line number Diff line number Diff line change
Expand Up @@ -9,8 +9,8 @@ class BendersByBatch : public BendersMpi {

public:
BendersByBatch(BendersBaseOptions const &options, Logger logger,
Writer writer, mpi::environment &env,
mpi::communicator &world);
Writer writer, mpi::environment &env, mpi::communicator &world,
std::shared_ptr<MathLoggerDriver> mathLoggerDriver);
~BendersByBatch() override = default;
void Run() override;
void BuildCut(const std::vector<std::string> &batch_sub_problems,
Expand Down
40 changes: 30 additions & 10 deletions src/cpp/benders/benders_core/BendersBase.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,14 @@
#include "solver_utils.h"

BendersBase::BendersBase(BendersBaseOptions options, Logger logger,
Writer writer)
Writer writer,
std::shared_ptr<MathLoggerDriver> mathLoggerDriver)
: _options(std::move(options)),
_csv_file_path(std::filesystem::path(_options.OUTPUTROOT) /
(_options.CSV_NAME + ".csv")),
_logger(std::move(logger)),
_writer(std::move(writer)) {}
_writer(std::move(writer)),
mathLoggerDriver_(mathLoggerDriver) {}

/*!
* \brief Initialize set of data used in the loop
Expand All @@ -34,7 +36,7 @@ void BendersBase::init_data() {
_data.best_it = 0;
_data.stopping_criterion = StoppingCriterion::empty;
_data.is_in_initial_relaxation = false;
_data.number_of_subproblem_resolved = 0;
_data.cumulative_number_of_subproblem_solved = 0;
}

void BendersBase::OpenCsvFile() {
Expand Down Expand Up @@ -177,7 +179,7 @@ bool BendersBase::ShouldRelaxationStop() const {
*
*/
void BendersBase::UpdateStoppingCriterion() {
if (_data.elapsed_time > _options.TIME_LIMIT)
if (_data.benders_time > _options.TIME_LIMIT)
_data.stopping_criterion = StoppingCriterion::timelimit;
else if ((_options.MAX_ITERATIONS != -1) &&
(_data.it >= _options.MAX_ITERATIONS))
Expand Down Expand Up @@ -467,7 +469,7 @@ LogData BendersBase::FinalLogData() const {
result.subproblem_cost = best_iteration_data.subproblem_cost;
result.invest_cost = best_iteration_data.invest_cost;
result.cumulative_number_of_subproblem_resolved =
_data.number_of_subproblem_resolved +
_data.cumulative_number_of_subproblem_solved +
cumulative_number_of_subproblem_resolved_before_resume;

return result;
Expand Down Expand Up @@ -525,7 +527,7 @@ Output::Iteration BendersBase::iteration(
masterDataPtr_l->_invest_cost + masterDataPtr_l->_operational_cost;
iteration.candidates = candidates_data(masterDataPtr_l);
iteration.cumulative_number_of_subproblem_resolved =
_data.number_of_subproblem_resolved +
_data.cumulative_number_of_subproblem_solved +
cumulative_number_of_subproblem_resolved_before_resume;
return iteration;
}
Expand Down Expand Up @@ -648,10 +650,10 @@ LogData BendersBase::bendersDataToLogData(
optimal_gap,
optimal_gap / data.best_ub,
_options.MAX_ITERATIONS,
data.elapsed_time,
data.benders_time,
data.timer_master,
data.subproblems_walltime,
data.number_of_subproblem_resolved +
data.cumulative_number_of_subproblem_solved +
cumulative_number_of_subproblem_resolved_before_resume};
}
void BendersBase::set_solver_log_file(const std::filesystem::path &log_file) {
Expand Down Expand Up @@ -772,6 +774,24 @@ void BendersBase::SetSubproblemCost(const double &subproblem_cost) {
_data.subproblem_cost = subproblem_cost;
}

/*!
* \brief Update maximum and minimum of simplex iterations
*
* \param subproblem_iterations : number of iterations done with the subproblem
*
*/
void BendersBase::BoundSimplexIterations(int subproblem_iterations){

_data.max_simplexiter = (_data.max_simplexiter < subproblem_iterations) ? subproblem_iterations : _data.max_simplexiter;
_data.min_simplexiter = (_data.min_simplexiter > subproblem_iterations) ? subproblem_iterations : _data.min_simplexiter;

}

void BendersBase::ResetSimplexIterationsBounds()
{
_data.max_simplexiter = 0;
_data.min_simplexiter = std::numeric_limits<int>::max();
}
bool BendersBase::IsResumeMode() const { return _options.RESUME; }

void BendersBase::UpdateMaxNumberIterationResumeMode(
Expand All @@ -786,7 +806,7 @@ void BendersBase::UpdateMaxNumberIterationResumeMode(
}
}

double BendersBase::execution_time() const { return _data.elapsed_time; }
double BendersBase::execution_time() const { return _data.benders_time; }
LogData BendersBase::GetBestIterationData() const {
return best_iteration_data;
}
Expand Down Expand Up @@ -832,7 +852,7 @@ void BendersBase::ClearCurrentIterationCutTrace() const {
}
void BendersBase::EndWritingInOutputFile() const {
_writer->updateEndTime();
_writer->write_duration(_data.elapsed_time);
_writer->write_duration(_data.benders_time);
SaveSolutionInOutputFile();
}
double BendersBase::GetBendersTime() const { return benders_timer.elapsed(); }
Expand Down
77 changes: 77 additions & 0 deletions src/cpp/benders/benders_core/BendersMathLogger.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,77 @@
#include "BendersMathLogger.h"

#include "LogUtils.h"
#include "LoggerUtils.h"

HeadersManager::HeadersManager(HEADERSTYPE type, const BENDERSMETHOD& method) {
headers_list.push_back("Ite");
headers_list.push_back("Lb");
if (method == BENDERSMETHOD::BENDERS) {
headers_list.push_back("Ub");
headers_list.push_back("BestUb");
headers_list.push_back("AbsGap");
headers_list.push_back("RelGap");
}
headers_list.push_back("MinSpx");
headers_list.push_back("MaxSpx");

if (type == HEADERSTYPE::LONG || method == BENDERSMETHOD::BENDERSBYBATCH) {
headers_list.push_back("NbSubPbSolv");
}

if (type == HEADERSTYPE::LONG) {
headers_list.push_back("CumulNbSubPbSolv");
}
headers_list.push_back("IteTime (s)");
headers_list.push_back("MasterTime (s)");
headers_list.push_back("SPWallTime (s)");
if (type == HEADERSTYPE::LONG) {
headers_list.push_back("SPCpuTime (s)");
headers_list.push_back("NotSolvingWallTime (s)");
}
}

LogDestination::LogDestination(std::streamsize width)
: stream_(&std::cout), width_(width) {
(*stream_) << std::unitbuf;
}

LogDestination::LogDestination(const std::filesystem::path& file_path,
std::streamsize width)
: width_(width) {
file_stream_.open(file_path, std::ofstream::out | std::ofstream::trunc);
if (file_stream_.is_open()) {
stream_ = &file_stream_;
(*stream_) << std::unitbuf;
} else {
std::ostringstream err_msg;
err_msg << PrefixMessage(LogUtils::LOGLEVEL::WARNING, MATHLOGGERCONTEXT)
<< "Could not open the file: "
<< std::quoted(file_path.string().c_str()) << "\n";
std::cerr << err_msg.str();
}
}
void MathLoggerDriver::add_logger(
std::shared_ptr<MathLoggerImplementation> logger) {
if (logger) {
math_loggers_.push_back(logger);
}
}

void MathLoggerDriver::Print(const CurrentIterationData& data) {
for (auto logger : math_loggers_) {
logger->Print(data);
}
}

void MathLoggerDriver::write_header() {
for (auto logger : math_loggers_) {
logger->write_header();
}
}

void MathLoggerDriver::display_message(const std::string& str) {
for (auto logger : math_loggers_) {
logger->display_message(str);
}
}
1 change: 1 addition & 0 deletions src/cpp/benders/benders_core/BendersStructsDatas.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -8,3 +8,4 @@ Point WorkerMasterData::get_x_cut() const { return *_x_cut; }
Point WorkerMasterData::get_min_invest() const { return *_min_invest; }

Point WorkerMasterData::get_max_invest() const { return *_max_invest; }

4 changes: 3 additions & 1 deletion src/cpp/benders/benders_core/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,9 @@ add_library (benders_core STATIC
${CMAKE_CURRENT_SOURCE_DIR}/LastIterationWriter.cpp
${CMAKE_CURRENT_SOURCE_DIR}/LastIterationReader.cpp
${CMAKE_CURRENT_SOURCE_DIR}/LastIterationPrinter.cpp
${CMAKE_CURRENT_SOURCE_DIR}/StartUp.cpp)
${CMAKE_CURRENT_SOURCE_DIR}/StartUp.cpp
${CMAKE_CURRENT_SOURCE_DIR}/BendersMathLogger.cpp
)

get_target_property(JSON_INC_PATH jsoncpp_lib INTERFACE_INCLUDE_DIRECTORIES)

Expand Down
2 changes: 1 addition & 1 deletion src/cpp/benders/benders_core/SimulationOptions.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -112,7 +112,7 @@ void SimulationOptions::set_weights() {
void SimulationOptions::print(std::ostream &stream) const {
#define BENDERS_OPTIONS_MACRO(name__, type__, default__, \
deserialization_method__) \
stream << std::setw(30) << #name__ << std::setw(50) << name__ << std::endl;
stream << std::setw(30) << #name__ << std::setw(50)<<std::boolalpha << name__ << std::endl;
#include "SimulationOptions.hxx"
#undef BENDERS_OPTIONS_MACRO
stream << std::endl;
Expand Down
Loading

0 comments on commit 32c263b

Please sign in to comment.