From 0dd59bde71a5731a293a5f42a6a737409ce2ce1b Mon Sep 17 00:00:00 2001
From: Tobias Leibner <tobias.leibner@googlemail.com>
Date: Mon, 6 Apr 2020 10:17:00 +0200
Subject: [PATCH] [timestepper] change output format for timings

---
 .../entropic-coords-mn-discretization.hh      |  2 --
 .../adaptive-rungekutta-kinetic.hh            |  6 -----
 .../tools/timestepper/explicit-rungekutta.hh  |  5 ----
 dune/gdt/tools/timestepper/fractional-step.hh |  7 -----
 dune/gdt/tools/timestepper/interface.hh       | 27 ++++++++++++-------
 5 files changed, 17 insertions(+), 30 deletions(-)

diff --git a/dune/gdt/test/momentmodels/entropic-coords-mn-discretization.hh b/dune/gdt/test/momentmodels/entropic-coords-mn-discretization.hh
index 82fdbe4d5..8b2b5434d 100644
--- a/dune/gdt/test/momentmodels/entropic-coords-mn-discretization.hh
+++ b/dune/gdt/test/momentmodels/entropic-coords-mn-discretization.hh
@@ -257,8 +257,6 @@ struct HyperbolicEntropicCoordsMnDiscretization
 
     // *********************** create operators and timesteppers ************************************
     NumericalKineticFlux<GV, MomentBasis, EntropyFluxType> numerical_flux(*analytical_flux, *basis_functions);
-    // do not use parallelisation here, as the advection operator does almost no work (allows to use alpha_vec without
-    // mutexes)
     AdvectionOperatorType advection_operator(
         grid_view, numerical_flux, advection_source_space, fv_space, /*use_tbb*/ true);
 
diff --git a/dune/gdt/tools/timestepper/adaptive-rungekutta-kinetic.hh b/dune/gdt/tools/timestepper/adaptive-rungekutta-kinetic.hh
index 09d2ad8a4..2c2f33794 100644
--- a/dune/gdt/tools/timestepper/adaptive-rungekutta-kinetic.hh
+++ b/dune/gdt/tools/timestepper/adaptive-rungekutta-kinetic.hh
@@ -256,12 +256,6 @@ public:
     auto& t = current_time();
     auto& alpha_n = current_solution();
 
-    // store statistics
-    this->times_.push_back(t);
-    auto time = std::chrono::steady_clock::now();
-    std::chrono::duration<double> wall_time = time - this->begin_time_;
-    this->wall_times_.push_back(wall_time.count());
-
     while (mixed_error > 1.) {
       bool skip_error_computation = false;
       actual_dt *= time_step_scale_factor;
diff --git a/dune/gdt/tools/timestepper/explicit-rungekutta.hh b/dune/gdt/tools/timestepper/explicit-rungekutta.hh
index f0eafb79b..04199eeef 100644
--- a/dune/gdt/tools/timestepper/explicit-rungekutta.hh
+++ b/dune/gdt/tools/timestepper/explicit-rungekutta.hh
@@ -245,11 +245,6 @@ public:
     const RangeFieldType actual_dt = std::min(dt, max_dt);
     auto& t = current_time();
 
-    // store statistics
-    this->times_.push_back(t);
-    auto time = std::chrono::steady_clock::now();
-    std::chrono::duration<double> wall_time = time - this->begin_time_;
-    this->wall_times_.push_back(wall_time.count());
     this->dts_.push_back(actual_dt);
 
     // calculate stages
diff --git a/dune/gdt/tools/timestepper/fractional-step.hh b/dune/gdt/tools/timestepper/fractional-step.hh
index 590527c93..4e51e936e 100644
--- a/dune/gdt/tools/timestepper/fractional-step.hh
+++ b/dune/gdt/tools/timestepper/fractional-step.hh
@@ -65,10 +65,7 @@ public:
   {
     auto& t = current_time();
     const RangeFieldType actual_dt = std::min(dt, max_dt);
-    this->times_.push_back(t);
     auto time = std::chrono::steady_clock::now();
-    std::chrono::duration<double> wall_time = time - this->begin_time_;
-    this->wall_times_.push_back(wall_time.count());
     this->dts_.push_back(actual_dt);
     const auto dt_1 = first_stepper_.solve(t + actual_dt, dt, -1, 0, false, false, false, false, false);
     const auto dt_2 = second_stepper_.solve(t + actual_dt, dt_1, -1, 0, false, false, false, false, false);
@@ -122,10 +119,6 @@ public:
   {
     auto& t = current_time();
     const RangeFieldType actual_dt = std::min(dt, max_dt);
-    this->times_.push_back(t);
-    auto time = std::chrono::steady_clock::now();
-    std::chrono::duration<double> wall_time = time - this->begin_time_;
-    this->wall_times_.push_back(wall_time.count());
     this->dts_.push_back(actual_dt);
     first_stepper_.solve(
         t + actual_dt / 2, actual_dt / 2, static_cast<size_t>(-1), 0, false, false, false, false, false);
diff --git a/dune/gdt/tools/timestepper/interface.hh b/dune/gdt/tools/timestepper/interface.hh
index de4e26f76..ec38818f5 100644
--- a/dune/gdt/tools/timestepper/interface.hh
+++ b/dune/gdt/tools/timestepper/interface.hh
@@ -197,7 +197,6 @@ public:
   {
     if (reset_begin_time)
       begin_time_ = std::chrono::steady_clock::now();
-
     RangeFieldType dt = initial_dt;
     RangeFieldType t = current_time();
     assert(Dune::XT::Common::FloatCmp::ge(t_end, t));
@@ -224,6 +223,8 @@ public:
                 stringifier,
                 visualizer);
 
+    // store initial time
+    timepoints_.push_back(t);
     while (Dune::XT::Common::FloatCmp::lt(t, t_end)) {
       RangeFieldType max_dt = dt;
       // match saving times and t_end exactly
@@ -233,8 +234,13 @@ public:
         max_dt = std::min(next_save_time - t, max_dt);
 
       // do a timestep
+      const auto walltime_before_step = std::chrono::steady_clock::now();
       dt = step(dt, max_dt);
+      const auto walltime_after_step = std::chrono::steady_clock::now();
       t = current_time();
+      timepoints_.push_back(t);
+      std::chrono::duration<double> step_time = walltime_after_step - walltime_before_step;
+      step_walltimes_.push_back(step_time.count());
 
       // augment time step counter
       ++time_step_counter;
@@ -262,11 +268,11 @@ public:
         next_output_time += output_interval;
       }
     } // while (t < t_end)
-    times_.push_back(t);
-    const auto time = std::chrono::steady_clock::now();
-    std::chrono::duration<double> wall_time = time - this->begin_time_;
-    wall_times_.push_back(wall_time.count());
+    solve_walltime_ = std::chrono::steady_clock::now() - begin_time_;
+    // for the last time point there is no actual dt and no computation time as the step is not taken anymore, so we
+    // store the estimate for the next timestep and the time for the whole solution process
     dts_.push_back(dt);
+    step_walltimes_.push_back(solve_walltime_.count());
 
     return dt;
   } // ... solve(...)
@@ -474,11 +480,11 @@ public:
   {
     const std::string filename = prefix + "_timings.txt";
     std::ofstream timings_file(filename);
-    timings_file << "step t dt walltime" << std::endl;
+    timings_file << "step t dt steptime" << std::endl;
     timings_file << std::setprecision(15);
     for (size_t ii = 0; ii < dts_.size(); ++ii) {
-      timings_file << ii + 1 << " " << XT::Common::to_string(times_[ii], 15) << " "
-                   << XT::Common::to_string(dts_[ii], 15) << " " << XT::Common::to_string(wall_times_[ii], 15)
+      timings_file << ii + 1 << " " << XT::Common::to_string(timepoints_[ii], 15) << " "
+                   << XT::Common::to_string(dts_[ii], 15) << " " << XT::Common::to_string(step_walltimes_[ii], 15)
                    << std::endl;
     }
     timings_file.close();
@@ -491,8 +497,9 @@ protected:
   DiscreteSolutionType* solution_;
   std::chrono::time_point<std::chrono::steady_clock> begin_time_;
   std::vector<double> dts_;
-  std::vector<double> times_;
-  std::vector<double> wall_times_;
+  std::vector<double> timepoints_;
+  std::vector<double> step_walltimes_;
+  std::chrono::duration<double> solve_walltime_;
 }; // class TimeStepperInterface
 
 
-- 
GitLab