Refactor the log messages emitted while creating the Schedule object

A maximum of N dates keywords are printed to stdout, afterwards logging will
only go to PRT file
This commit is contained in:
Joakim Hove 2020-10-10 08:59:38 +02:00
parent 79ad189d65
commit 8f90bf9387

View File

@ -26,10 +26,12 @@
#include <string>
#include <unordered_set>
#include <vector>
#include <functional>
#include <fmt/format.h>
#include <opm/common/OpmLog/LogUtil.hpp>
#include <opm/common/OpmLog/OpmLog.hpp>
#include <opm/common/utility/numeric/cmp.hpp>
#include <opm/common/utility/String.hpp>
#include <opm/common/utility/OpmInputError.hpp>
@ -42,6 +44,7 @@
#include <opm/parser/eclipse/Parser/ErrorGuard.hpp>
#include <opm/parser/eclipse/Parser/ParseContext.hpp>
#include <opm/parser/eclipse/Parser/ParserKeywords/P.hpp>
#include <opm/parser/eclipse/Parser/ParserKeywords/S.hpp>
#include <opm/parser/eclipse/Parser/ParserKeywords/W.hpp>
#include <opm/parser/eclipse/EclipseState/EclipseState.hpp>
@ -301,14 +304,60 @@ namespace {
handlePYACTION(python, input_path, keyword, currentStep);
}
namespace {
class ScheduleLogger {
public:
explicit ScheduleLogger(bool restart_skip)
{
if (restart_skip)
this->log_function = &OpmLog::note;
else
this->log_function = &OpmLog::info;
}
void operator()(const std::string& msg) {
this->log_function(msg);
}
void info(const std::string& msg) {
OpmLog::info(msg);
}
void complete_step(const std::string& msg) {
this->step_count += 1;
if (this->step_count == this->max_print) {
this->log_function(msg);
OpmLog::info("Report limit reached, see PRT-file for remaining Schedule initialization.\n");
this->log_function = &OpmLog::note;
} else
this->log_function( msg + "\n");
};
void restart() {
this->step_count = 0;
this->log_function = &OpmLog::info;
}
private:
std::size_t step_count = 0;
std::size_t max_print = 5;
void (*log_function)(const std::string&);
};
}
void Schedule::iterateScheduleSection(std::shared_ptr<const Opm::Python> python, const std::string& input_path, const ParseContext& parseContext , ErrorGuard& errors, const SCHEDULESection& section , const EclipseGrid& grid,
const FieldPropsManager& fp) {
std::vector<std::pair< const DeckKeyword* , std::size_t> > rftProperties;
const auto& unit_system = section.unitSystem();
std::string time_unit = unit_system.name(UnitSystem::measure::time);
auto convert_time = [&unit_system](double seconds) { return unit_system.from_si(UnitSystem::measure::time, seconds); };
std::size_t keywordIdx = 0;
std::string current_file;
const auto& time_map = this->m_timeMap;
/*
The keywords in the skiprest_whitelist set are loaded from the
SCHEDULE section even though the SKIPREST keyword is in action. The
@ -334,37 +383,62 @@ namespace {
*/
auto restart_skip = currentStep < this->m_timeMap.restart_offset();
ScheduleLogger logger(restart_skip);
{
const auto& schedule_keyword = section.getKeyword<ParserKeywords::SCHEDULE>();
const auto& location = schedule_keyword.location();
current_file = location.filename;
logger.info(fmt::format("Processing dynamic information from\n{} line {}", current_file, location.lineno));
if (restart_skip)
logger.info(fmt::format("This is a restarted run - skipping until report step {} at {}", time_map.restart_offset(), Schedule::formatDate(time_map.restart_time())));
logger(fmt::format("Initializing report step {}/{} at {} {} {} line {}",
currentStep + 1,
this->size(),
Schedule::formatDate(this->getStartTime()),
convert_time(time_map.getTimePassedUntil(currentStep)),
time_unit,
location.lineno));
}
while (true) {
if (keywordIdx == section.size())
break;
const auto& keyword = section.getKeyword(keywordIdx);
const auto& location = keyword.location();
if (location.filename != current_file) {
logger(fmt::format("Reading from: {} line {}", location.filename, location.lineno));
current_file = location.filename;
}
if (keyword.name() == "DATES") {
const auto& location = keyword.location();
checkIfAllConnectionsIsShut(currentStep);
for (const auto& record : keyword) {
if (restart_skip) {
auto deck_time = TimeMap::timeFromEclipse(record);
if (deck_time == this->m_timeMap.restart_time()) {
if (deck_time == time_map.restart_time()) {
restart_skip = false;
currentStep = this->m_timeMap.restart_offset();
OpmLog::info(fmt::format("Found restart date {}", Schedule::formatDate(deck_time)));
currentStep = time_map.restart_offset();
logger.restart();
logger(fmt::format("Found restart date {}", Schedule::formatDate(deck_time)));
} else
OpmLog::info(fmt::format("Skipping DATES keyword {}", Schedule::formatDate(deck_time)));
logger(fmt::format("Skipping DATES keyword {}", Schedule::formatDate(deck_time)));
} else {
currentStep += 1;
if (currentStep < this->size()) {
const auto& end_date = Schedule::formatDate(this->simTime(currentStep));
const auto& start_date = Schedule::formatDate(this->simTime(currentStep - 1));
const auto& start_date = Schedule::formatDate(this->simTime(currentStep));
const auto& days = convert_time(this->stepLength(currentStep - 1));
OpmLog::info(fmt::format("Complete report step {:4}: {} - {} {:3.0f} {} {} line {}",
currentStep,
start_date,
end_date,
days,
time_unit,
location.filename,
location.lineno));
const auto& days_total = convert_time(time_map.getTimePassedUntil(currentStep));
logger.complete_step(fmt::format("Complete report step {0} ({1} {2}) at {3} ({4} {2})", currentStep, days, time_unit, start_date, days_total));
logger(fmt::format("Initializing report step {}/{} at {} ({} {}) - line {}",
currentStep + 1,
this->size(),
start_date,
convert_time(time_map.getTimePassedUntil(currentStep)),
time_unit,
location.lineno));
}
}
}
@ -375,12 +449,12 @@ namespace {
if (keyword.name() == "TSTEP") {
checkIfAllConnectionsIsShut(currentStep);
if (restart_skip)
OpmLog::info(OpmInputError::format("Skipping TSTEP keyword at {file} line {line}", keyword.location()));
logger(OpmInputError::format("Skipping TSTEP keyword at {file} line {line}", keyword.location()));
else {
for (const auto& tstep : keyword.getRecord(0).getItem(0).getSIDoubleData()) {
currentStep += 1;
const auto& end_date = Schedule::formatDate( this->simTime(currentStep) );
OpmLog::info(fmt::format("TSTEP {:4} {} {} -> {}", currentStep, convert_time(tstep), time_unit, end_date));
logger.complete_step(fmt::format("TSTEP {:4} {} {} -> {}", currentStep, convert_time(tstep), time_unit, end_date));
}
}
keywordIdx++;
@ -388,7 +462,7 @@ namespace {
}
if (restart_skip && skiprest_whitelist.count(keyword.name()) == 0) {
OpmLog::info("Skipping keyword: " + keyword.name() + " while loading SCHEDULE section");
logger(fmt::format("Skipping keyword: {} while loading SCHEDULE section", keyword.name()));
keywordIdx++;
continue;
}
@ -416,7 +490,7 @@ namespace {
keywordIdx++;
continue;
}
logger(fmt::format("Processing keyword {} at line {}", location.keyword, location.lineno));
this->handleKeyword(python,
input_path,
currentStep,