Skip to content

Clean-up main model: Add logger interface #1093

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 31 commits into
base: main
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from 21 commits
Commits
Show all changes
31 commits
Select commit Hold shift + click to select a range
e0b3f57
logging calculation info
mgovers Aug 15, 2025
57088c8
Merge branch 'feature/timer-using-codes' into feature/logger-interface
mgovers Aug 15, 2025
adc6651
Merge remote-tracking branch 'origin/main' into feature/logger-interface
mgovers Aug 19, 2025
70cf27c
Merge remote-tracking branch 'origin/feature/timer-using-codes' into …
mgovers Aug 19, 2025
5f4ec7c
cleanup
mgovers Aug 19, 2025
83a4459
replace calculation info with generic logger
mgovers Aug 19, 2025
3f8c22e
Merge remote-tracking branch 'origin/feature/timer-using-codes' into …
mgovers Aug 20, 2025
72ec561
Merge branch 'main' into feature/logger-interface
mgovers Aug 20, 2025
c1d6b99
improve header include order
mgovers Aug 20, 2025
cf7534e
extend process
mgovers Aug 20, 2025
d3d1ae0
fix tests
mgovers Aug 20, 2025
30057cb
use report when reporting
mgovers Aug 20, 2025
644d8d9
improve type exposure
mgovers Aug 20, 2025
4432cfc
fix
mgovers Aug 20, 2025
9fc3c39
remove remaining headers from calculation info
mgovers Aug 20, 2025
008e980
fix benchmark compilation
mgovers Aug 21, 2025
485bad7
Merge remote-tracking branch 'origin/main' into feature/logger-interface
mgovers Aug 21, 2025
3cc60aa
apply suggestion
mgovers Aug 22, 2025
126b1c4
clang-tidy
mgovers Aug 25, 2025
69b737a
return void
mgovers Aug 25, 2025
97cf176
fix compilation
mgovers Aug 25, 2025
babf8b1
remove log dispatcher cfr. offline discussion
mgovers Aug 27, 2025
aac61a1
resolve sonar cloud
mgovers Aug 27, 2025
6bdea5f
resolve sonar cloud
mgovers Aug 27, 2025
e6faf8a
sonar cloud
mgovers Aug 27, 2025
f4ba5a7
fix
mgovers Aug 27, 2025
b700a08
noexcept
mgovers Aug 27, 2025
bbc901e
noexcept
mgovers Aug 27, 2025
ff561f1
fix compilation
mgovers Aug 27, 2025
474a313
unused variable
mgovers Aug 27, 2025
720984d
sonar cloud
mgovers Aug 27, 2025
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
Original file line number Diff line number Diff line change
Expand Up @@ -6,12 +6,13 @@

// handle dataset and buffer related stuff

#include "dataset_fwd.hpp"
#include "meta_data.hpp"

#include "../common/common.hpp"
#include "../common/counting_iterator.hpp"
#include "../common/exception.hpp"
#include "../common/iterator_facade.hpp"
#include "dataset_fwd.hpp"
#include "meta_data.hpp"

#include <span>
#include <string_view>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,15 +4,77 @@

#pragma once

#include "logging.hpp"
#include "logging_impl.hpp"

#include <cstddef>
#include <functional>
#include <map>
#include <string>

namespace power_grid_model {
namespace common::logging {
class CalculationInfo : public NoLogger {
using Data = std::map<LogEvent, double>;

using CalculationInfo = std::map<LogEvent, double>;
public:
using Report = std::add_lvalue_reference_t<std::add_const_t<Data>>;
static_assert(std::same_as<Report, Data const&>);

void log(LogEvent tag, double value) override { log_impl(tag, value); }
void log(LogEvent tag, Idx value) override { log_impl(tag, static_cast<double>(value)); }

private:
Data data_;

void log_impl(LogEvent tag, double value) {
using enum LogEvent;

switch (tag) {
case total:
case build_model:
case total_single_calculation_in_thread:
case total_batch_calculation_in_thread:
case copy_model:
case update_model:
case restore_model:
case scenario_exception:
case recover_from_bad:
case prepare:
case create_math_solver:
case math_calculation:
case math_solver:
case initialize_calculation:
case preprocess_measured_value:
case prepare_matrix:
case prepare_matrix_including_prefactorization:
case prepare_matrices:
case initialize_voltages:
case calculate_rhs:
case prepare_lhs_rhs:
case solve_sparse_linear_equation:
case solve_sparse_linear_equation_prefactorized:
case iterate_unknown:
case calculate_math_result:
case produce_output:
accumulate_log(tag, value);
return;
case iterative_pf_solver_max_num_iter:
case max_num_iter:
maximize_log(tag, value);
return;
default:
return;
}
}
void accumulate_log(LogEvent tag, double value) { data_[tag] += value; }
void maximize_log(LogEvent tag, double value) {
if (auto& stored_value = data_[tag]; value > stored_value) {
stored_value = value;
}
}

public:
Report report() const { return data_; }
void clear() { data_.clear(); }
};
} // namespace common::logging

using common::logging::CalculationInfo;
} // namespace power_grid_model
Original file line number Diff line number Diff line change
Expand Up @@ -6,11 +6,11 @@

#include "common.hpp"

#include <memory>
#include <string_view>

namespace power_grid_model {
namespace common::logging {

enum class LogEvent : int16_t {
unknown = -1,
total = 0000, // TODO(mgovers): find other error code?
Expand Down Expand Up @@ -43,8 +43,26 @@ enum class LogEvent : int16_t {
max_num_iter = 2248, // TODO(mgovers): find other error code
};

struct Logger {
virtual void log(LogEvent tag) = 0;
virtual void log(LogEvent tag, std::string_view message) = 0;
virtual void log(LogEvent tag, double value) = 0;
virtual void log(LogEvent tag, Idx value) = 0;

// creates a new logger of the same type as the current one
virtual std::unique_ptr<Logger> clone() const = 0;

virtual ~Logger() = default;
};

struct LogDispatch : public Logger {
virtual void registrar(Logger* logger) = 0;
virtual void deregistrar(Logger* logger) = 0;
};

} // namespace common::logging

using common::logging::LogEvent;
using common::logging::Logger;

} // namespace power_grid_model
Original file line number Diff line number Diff line change
@@ -0,0 +1,68 @@
// SPDX-FileCopyrightText: Contributors to the Power Grid Model project <powergridmodel@lfenergy.org>
//
// SPDX-License-Identifier: MPL-2.0

#pragma once

#include "logging.hpp"

#include <string_view>
#include <vector>

namespace power_grid_model::common::logging {
class NoLogger : public Logger {
void log(LogEvent /*tag*/) override {}
void log(LogEvent /*tag*/, std::string_view /*message*/) override {}
void log(LogEvent /*tag*/, double /*value*/) override {}
void log(LogEvent /*tag*/, Idx /*value*/) override {}
std::unique_ptr<Logger> clone() const override { return std::make_unique<NoLogger>(); }
};

class LogDispatcher final : public LogDispatch {
public:
void log(LogEvent tag) override { log_impl(tag); }
void log(LogEvent tag, std::string_view message) override { log_impl(tag, message); }
void log(LogEvent tag, double value) override { log_impl(tag, value); }
void log(LogEvent tag, Idx value) override { log_impl(tag, value); }
void registrar(Logger* logger) override {
if (logger != nullptr && std::ranges::find(loggers_, logger) == loggers_.end()) {
loggers_.push_back(logger);
}
}
void deregistrar(Logger* logger) override {
if (logger != nullptr) {
std::erase(loggers_, logger);
}
}
std::unique_ptr<Logger> clone() const override { return std::make_unique<LogDispatcher>(); }

LogDispatcher() = default;
LogDispatcher(const LogDispatcher&) = delete;
LogDispatcher& operator=(const LogDispatcher&) = delete;
LogDispatcher(LogDispatcher&&) = default;
LogDispatcher& operator=(LogDispatcher&&) = default;
~LogDispatcher() override = default;

private:
std::vector<Logger*> loggers_;

template <typename... T>
constexpr void log_impl(LogEvent tag, T&&... values)
requires requires(Logger log_) {
{ log_.log(tag, values...) };
}
{
if (loggers_.size() == 1 && loggers_.front() != nullptr) { // allows perfect forwarding to log messages
loggers_.front()->log(tag, std::forward<T>(values)...);
} else {
for (auto& logger : loggers_) {
if (logger != nullptr) {
logger->log(tag, values...);
}
}
capturing::into_the_void(std::forward<T>(values)...);
Copy link
Member

Choose a reason for hiding this comment

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

values can be any count of arguments and maybe not all get used in logging and hence unused ones get sent to void?

Copy link
Member Author

@mgovers mgovers Aug 27, 2025

Choose a reason for hiding this comment

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

no this is about how to do perfect forwarding (in particular about using a moved object). an alternative would be

        if (auto const first_non_null = std::ranges::find_if(loggers_, [] (auto& logger) { return logger != nullptr; });
            first_non_null != loggers_.end()) {
            for (auto& logger : std::ranges::subrange(first_non_null + 1, loggers_.end());) {
                if (logger != nullptr) {
                    logger->log(tag, values...);
                }
            }
            (*first_non_null)->std::forward<T>(values)...);
        } else {
            capturing::into_the_void(std::forward<T>(values)...)
        }

Copy link
Member Author

Choose a reason for hiding this comment

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

by C++ guidelines: every object that was moved into the current function shall be moved again (for performance reasons).

Forwarding means that the object could be passed by const& or be moved into this object (or captured by value for small objects). You don't know. Therefore, you need to forward objects provided to this function again. But you can only forward once (otherwise, you might be moving an already moved object) and exactly once (cfr. the guideline)

capturing::into_the_void is a sink that consumes objects that would otherwise not be moved into this function.

Copy link
Member Author

Choose a reason for hiding this comment

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

cfr. offline discussion: removed the LogDispatcher altogether

}
}
};

} // namespace power_grid_model::common::logging
Original file line number Diff line number Diff line change
Expand Up @@ -4,12 +4,10 @@

#pragma once

#include "calculation_info.hpp"
#include "common.hpp"
#include "logging.hpp"

#include <chrono>
#include <iomanip>
#include <sstream>

namespace power_grid_model {
Expand All @@ -19,13 +17,13 @@ using Duration = std::chrono::duration<double>;

class Timer {
private:
CalculationInfo* info_;
Logger* info_;
LogEvent code_;
Clock::time_point start_;

public:
Timer() : info_(nullptr), code_{LogEvent::unknown} {};
Timer(CalculationInfo& info, LogEvent code) : info_{&info}, code_{code}, start_{Clock::now()} {}
Timer(Logger& info, LogEvent code) : info_{&info}, code_{code}, start_{Clock::now()} {}

Timer(Timer const&) = delete;
Timer(Timer&&) = default;
Expand Down Expand Up @@ -57,7 +55,7 @@ class Timer {
if (info_ != nullptr) {
auto const now = Clock::now();
auto const duration = Duration(now - start_);
info_->operator[](code_) += static_cast<double>(duration.count());
info_->log(code_, static_cast<double>(duration.count()));
info_ = nullptr;
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -4,10 +4,8 @@

#pragma once

#include <numeric>

#include "branch.hpp"
#include <iostream>
#include "line_utils.hpp"

#include "../auxiliary/input.hpp"
#include "../auxiliary/output.hpp"
Expand All @@ -16,7 +14,9 @@
#include "../common/common.hpp"
#include "../common/matrix_utils.hpp"
#include "../common/three_phase_tensor.hpp"
#include "line_utils.hpp"

#include <iostream>
#include <numeric>

namespace power_grid_model {

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -181,7 +181,7 @@ class JobDispatch {
} catch (...) {
messages[scenario_idx] = "unknown exception";
}
info.merge(adapter.get_calculation_info());
main_core::merge_into(info, adapter.get_calculation_info());
};
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -10,16 +10,9 @@

namespace power_grid_model::main_core {

inline CalculationInfo& merge_into(CalculationInfo& destination, CalculationInfo const& source) {
static constexpr auto key =
LogEvent::iterative_pf_solver_max_num_iter; // TODO(mgovers) also add LogEvent::max_num_iter; this is a bug
// in main
for (auto const& [k, v] : source) {
if (k == key) {
destination[k] = std::max(destination[k], v);
} else {
destination[k] += v;
}
inline Logger& merge_into(Logger& destination, CalculationInfo const& source) {
for (const auto& [tag, value] : source.report()) {
destination.log(tag, value);
}
return destination;
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -84,7 +84,7 @@ template <symmetry_tag sym_type> class IterativeLinearSESolver {
perm_(y_bus.size()) {}

SolverOutput<sym> run_state_estimation(YBus<sym> const& y_bus, StateEstimationInput<sym> const& input,
double err_tol, Idx max_iter, CalculationInfo& calculation_info) {
double err_tol, Idx max_iter, Logger& log) {
// prepare
Timer main_timer;
Timer sub_timer;
Expand All @@ -93,22 +93,22 @@ template <symmetry_tag sym_type> class IterativeLinearSESolver {
output.bus_injection.resize(n_bus_);
double max_dev = std::numeric_limits<double>::max();

main_timer = Timer{calculation_info, LogEvent::math_solver};
main_timer = Timer{log, LogEvent::math_solver};

// preprocess measured value
sub_timer = Timer{calculation_info, LogEvent::preprocess_measured_value};
sub_timer = Timer{log, LogEvent::preprocess_measured_value};
MeasuredValues<sym> const measured_values{y_bus.shared_topology(), input};
auto const observability_result =
observability_check(measured_values, y_bus.math_topology(), y_bus.y_bus_structure());

// prepare matrix
sub_timer = Timer{calculation_info, LogEvent::prepare_matrix_including_prefactorization};
sub_timer = Timer{log, LogEvent::prepare_matrix_including_prefactorization};
prepare_matrix(y_bus, measured_values);
// prefactorize
sparse_solver_.prefactorize(data_gain_, perm_, observability_result.use_perturbation());

// initialize voltage with initial angle
sub_timer = Timer{calculation_info, LogEvent::initialize_voltages}; // TODO(mgovers): make scoped subtimers
sub_timer = Timer{log, LogEvent::initialize_voltages}; // TODO(mgovers): make scoped subtimers
RealValue<sym> const mean_angle_shift = measured_values.mean_angle_shift();
for (Idx bus = 0; bus != n_bus_; ++bus) {
output.u[bus] = exp(1.0i * (mean_angle_shift + math_topo_->phase_shift[bus]));
Expand All @@ -120,25 +120,24 @@ template <symmetry_tag sym_type> class IterativeLinearSESolver {
if (num_iter++ == max_iter) {
throw IterationDiverge{max_iter, max_dev, err_tol};
}
sub_timer = Timer{calculation_info, LogEvent::calculate_rhs};
sub_timer = Timer{log, LogEvent::calculate_rhs};
prepare_rhs(y_bus, measured_values, output.u);
// solve with prefactorization
sub_timer = Timer{calculation_info, LogEvent::solve_sparse_linear_equation_prefactorized};
sub_timer = Timer{log, LogEvent::solve_sparse_linear_equation_prefactorized};
sparse_solver_.solve_with_prefactorized_matrix(data_gain_, perm_, x_rhs_, x_rhs_);
sub_timer = Timer{calculation_info, LogEvent::iterate_unknown};
sub_timer = Timer{log, LogEvent::iterate_unknown};
max_dev = iterate_unknown(output.u, measured_values.has_angle());
};

// calculate math result
sub_timer = Timer{calculation_info, LogEvent::calculate_math_result};
sub_timer = Timer{log, LogEvent::calculate_math_result};
detail::calculate_se_result<sym>(y_bus, measured_values, output);

// Manually stop timers to avoid "Max number of iterations" to be included in the timing.
sub_timer.stop();
main_timer.stop();

calculation_info[LogEvent::max_num_iter] =
std::max(calculation_info[LogEvent::max_num_iter], static_cast<double>(num_iter));
log.log(LogEvent::max_num_iter, num_iter);

return output;
}
Expand Down
Loading
Loading