Merge pull request #1093 from PowerGridModel/feature/logger-interface

Clean-up main model: Add logger interface

Author: mgovers

power_grid_model_c/power_grid_model/include/power_grid_model/auxiliary/dataset.hpp

@@ -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>

power_grid_model_c/power_grid_model/include/power_grid_model/common/calculation_info.hpp

@@ -4,15 +4,89 @@
 
 #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 final : public Logger {
+    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&>);
 
+    CalculationInfo() = default;
+    CalculationInfo(CalculationInfo const&) = default;
+    CalculationInfo(CalculationInfo&&) noexcept = default;
+    CalculationInfo& operator=(CalculationInfo const&) = default;
+    CalculationInfo& operator=(CalculationInfo&&) noexcept = default;
+    ~CalculationInfo() override = default;
+
+    void log(LogEvent /*tag*/) override {
+        // ignore all such events for now
+    }
+    void log(LogEvent /*tag*/, std::string_view /*message*/) override {
+        // ignore all such events for now
+    }
+    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) {
+        auto& stored_value = data_[tag];
+        stored_value = std::max(value, stored_value);
+    }
+
+  public:
+    Report report() const { return data_; }
+    void clear() { data_.clear(); }
+};
+} // namespace common::logging
+
+using common::logging::CalculationInfo;
 } // namespace power_grid_model

power_grid_model_c/power_grid_model/include/power_grid_model/common/logging.hpp

@@ -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?
@@ -43,8 +43,26 @@ enum class LogEvent : int16_t {
     max_num_iter = 2248,                     // TODO(mgovers): find other error code
 };
 
+class Logger {
+  public:
+    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;
+
+    Logger(Logger&&) noexcept = default;
+    Logger& operator=(Logger&&) noexcept = default;
+    virtual ~Logger() = default;
+
+  protected:
+    Logger() = default;
+    Logger(Logger const&) = default;
+    Logger& operator=(Logger const&) = default;
+};
+
 } // namespace common::logging
 
 using common::logging::LogEvent;
+using common::logging::Logger;
 
 } // namespace power_grid_model

power_grid_model_c/power_grid_model/include/power_grid_model/common/logging_impl.hpp

@@ -0,0 +1,29 @@
+// SPDX-FileCopyrightText: Contributors to the Power Grid Model project <[email protected]>
+//
+// 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 {
+  public:
+    void log(LogEvent /*tag*/) override {
+        // no logging
+    }
+    void log(LogEvent /*tag*/, std::string_view /*message*/) override {
+        // no logging
+    }
+    void log(LogEvent /*tag*/, double /*value*/) override {
+        // no logging
+    }
+    void log(LogEvent /*tag*/, Idx /*value*/) override {
+        // no logging
+    }
+};
+
+} // namespace power_grid_model::common::logging

power_grid_model_c/power_grid_model/include/power_grid_model/common/timer.hpp

@@ -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 {
@@ -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() : info_{nullptr}, code_{LogEvent::unknown} {};
+    Timer(Logger& info, LogEvent code) : info_{&info}, code_{code}, start_{Clock::now()} {}
 
     Timer(Timer const&) = delete;
     Timer(Timer&&) = default;
@@ -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_, duration.count());
             info_ = nullptr;
         }
     }

power_grid_model_c/power_grid_model/include/power_grid_model/component/asym_line.hpp

@@ -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"
@@ -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 {
 

power_grid_model_c/power_grid_model/include/power_grid_model/job_dispatch.hpp

@@ -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());
         };
     }
 

power_grid_model_c/power_grid_model/include/power_grid_model/main_core/calculation_info.hpp

@@ -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;
 }

power_grid_model_c/power_grid_model/include/power_grid_model/math_solver/iterative_linear_se_solver.hpp

@@ -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;
@@ -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]));
@@ -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;
     }

power_grid_model_c/power_grid_model/include/power_grid_model/math_solver/iterative_pf_solver.hpp

@@ -25,7 +25,7 @@ template <symmetry_tag sym, typename DerivedSolver> class IterativePFSolver {
   public:
     friend DerivedSolver;
     SolverOutput<sym> run_power_flow(YBus<sym> const& y_bus, PowerFlowInput<sym> const& input, double err_tol,
-                                     Idx max_iter, CalculationInfo& calculation_info) {
+                                     Idx max_iter, Logger& log) {
         // get derived reference for derived solver class
         auto derived_solver = static_cast<DerivedSolver&>(*this);
 
@@ -34,11 +34,11 @@ template <symmetry_tag sym, typename DerivedSolver> class IterativePFSolver {
         output.u.resize(n_bus_);
         double max_dev = std::numeric_limits<double>::infinity();
 
-        Timer main_timer{calculation_info, LogEvent::math_solver};
+        Timer main_timer{log, LogEvent::math_solver};
 
         // initialize
         {
-            Timer const sub_timer{calculation_info, LogEvent::initialize_calculation};
+            Timer const sub_timer{log, LogEvent::initialize_calculation};
             // Further initialization specific to the derived solver
             derived_solver.initialize_derived_solver(y_bus, input, output);
         }
@@ -52,31 +52,30 @@ template <symmetry_tag sym, typename DerivedSolver> class IterativePFSolver {
             }
             {
                 // Prepare the matrices of linear equations to be solved
-                Timer const sub_timer{calculation_info, LogEvent::prepare_matrices};
+                Timer const sub_timer{log, LogEvent::prepare_matrices};
                 derived_solver.prepare_matrix_and_rhs(y_bus, input, output.u);
             }
             {
                 // Solve the linear equations
-                Timer const sub_timer{calculation_info, LogEvent::solve_sparse_linear_equation};
+                Timer const sub_timer{log, LogEvent::solve_sparse_linear_equation};
                 derived_solver.solve_matrix();
             }
             {
                 // Calculate maximum deviation of voltage at any bus
-                Timer const sub_timer{calculation_info, LogEvent::iterate_unknown};
+                Timer const sub_timer{log, LogEvent::iterate_unknown};
                 max_dev = derived_solver.iterate_unknown(output.u);
             }
         }
 
         // calculate math result
         {
-            Timer const sub_timer{calculation_info, LogEvent::calculate_math_result};
+            Timer const sub_timer{log, LogEvent::calculate_math_result};
             calculate_result(y_bus, input, output);
         }
         // Manually stop timers to avoid "Max number of iterations" to be included in the timing.
         main_timer.stop();
 
-        calculation_info[LogEvent::iterative_pf_solver_max_num_iter] =
-            std::max(calculation_info[LogEvent::iterative_pf_solver_max_num_iter], static_cast<double>(num_iter));
+        log.log(LogEvent::iterative_pf_solver_max_num_iter, num_iter);
 
         return output;
     }