]> https://gitweb.dealii.org/ - dealii.git/commitdiff
Fixup timer
authorDaniel Arndt <daniel.arndt@iwr.uni-heidelberg.de>
Fri, 23 Jun 2017 22:55:34 +0000 (00:55 +0200)
committerDaniel Arndt <daniel.arndt@iwr.uni-heidelberg.de>
Tue, 27 Jun 2017 12:00:10 +0000 (14:00 +0200)
doc/news/changes/minor/20170623DanielArndt [new file with mode: 0644]
include/deal.II/base/timer.h
source/base/timer.cc
tests/base/timer_04.cc [new file with mode: 0644]
tests/base/timer_04.output [new file with mode: 0644]
tests/base/timer_05.cc [new file with mode: 0644]
tests/base/timer_05.with_mpi=true.mpirun=1.output [new file with mode: 0644]

diff --git a/doc/news/changes/minor/20170623DanielArndt b/doc/news/changes/minor/20170623DanielArndt
new file mode 100644 (file)
index 0000000..e50b1a6
--- /dev/null
@@ -0,0 +1,5 @@
+New: The class Timer has the new functions get_total_data(),
+print_total_data, last_wall_time, cpu_time and last_cpu_time()
+for accessing information about the total run and the last lap now.
+<br>
+(Daniel Arndt, 2017/06/23)
index 44a9886ec8fbfe657dbe7fed4dcca8333b1a9fde..64dff3e92193df1e98d6cc9f6f436f36c078f84e 100644 (file)
@@ -95,24 +95,37 @@ public:
    * time for the MPI operations are not included in the timing but may slow
    * down your program.
    *
-   * This constructor is only available if the deal.II compiler is an MPI
-   * compiler.
+   * This constructor is only available if deal.II is compiled with MPI support.
    */
   Timer (MPI_Comm mpi_communicator,
          const bool sync_wall_time = false);
 
   /**
-   * Return a reference to the data structure with global timing information.
-   * Filled after calling stop().
+   * Return a reference to the data structure with global timing information
+   * for the last lap. Filled after calling stop().
    */
   const Utilities::MPI::MinMaxAvg &get_data() const;
 
   /**
-   * Prints the data to the given stream.
+   * Return a reference to the data structure with global timing information
+   * for the total run.
+   * Filled after calling stop().
+   */
+  const Utilities::MPI::MinMaxAvg &get_total_data() const;
+
+  /**
+   * Prints the data returned by get_data(), i.e. for the last lap,
+   * to the given stream.
    */
   template <class StreamType>
   void print_data(StreamType &stream) const;
 
+  /**
+   * Prints the data returned by get_total_data(), i.e. for the total run,
+   * to the given stream.
+   */
+  template <class StreamType>
+  void print_total_data(StreamType &stream) const;
 
 #endif
 
@@ -140,20 +153,45 @@ public:
   void restart();
 
   /**
-   * Access to the current CPU time without disturbing time measurement. The
-   * elapsed time is returned in units of seconds.
+   * Access to the current CPU time without stopping the timer.
+   * The elapsed time is returned in units of seconds.
+   *
+   * @deprecated Use cpu_time() instead.
    */
-  double operator() () const;
+  double operator() () const DEAL_II_DEPRECATED;
 
   /**
-   * Access to the current wall time without disturbing time measurement. The
-   * elapsed time is returned in units of seconds.
+   * Access to the current total wall time without stopping the timer.
+   * The elapsed time is returned in units of seconds.
    */
   double wall_time () const;
 
   /**
-   * Return the last lap time; the time taken between the last start()/stop()
+   * Access to the wall time for the currently running lap without stopping
+   * the timer.
+   * The elapsed time is returned in units of seconds.
+   */
+  double last_wall_time() const;
+
+  /**
+   * Access to the current total wall time without stopping the timer.
+   * The elapsed time is returned in units of seconds.
+   */
+  double cpu_time() const;
+
+  /**
+   * Access to the wall time for the currently running lap without stopping
+   * the timer.
+   * The elapsed time is returned in units of seconds.
+   */
+  double last_cpu_time() const;
+
+  /**
+   * Return the last lap time; the time taken between the last
+   * start()/stop()
    * call.
+   *
+   * @deprecated Use last_wall_time() instead.
    */
   double get_lap_time () const;
 
@@ -197,10 +235,15 @@ private:
   double              cumulative_wall_time;
 
   /**
-   * Stores the last lap time; the time between the last start()/stop() cycle.
+   * Stores the last lap wall time; the time between the last start()/stop() cycle.
    */
   double              last_lap_time;
 
+  /**
+   * Stores the last lap cpu time; the time between the last start()/stop() cycle.
+   */
+  double              last_lap_cpu_time;
+
   /**
    * Store whether the timer is presently running.
    */
@@ -221,9 +264,17 @@ private:
    * A structure for parallel wall time measurement that includes the minimum
    * time recorded among all processes, the maximum time as well as the
    * average time defined as the sum of all individual times divided by the
-   * number of MPI processes in the MPI_Comm.
+   * number of MPI processes in the MPI_Comm for the last lap.
    */
   Utilities::MPI::MinMaxAvg mpi_data;
+
+  /**
+   * A structure for parallel wall time measurement that includes the minimum
+   * time recorded among all processes, the maximum time as well as the
+   * average time defined as the sum of all individual times divided by the
+   * number of MPI processes in the MPI_Comm for the total run time.
+   */
+  Utilities::MPI::MinMaxAvg mpi_total_data;
 #endif
 };
 
@@ -732,18 +783,37 @@ Timer::get_data() const
 
 
 
+inline
+const Utilities::MPI::MinMaxAvg &
+Timer::get_total_data() const
+{
+  return mpi_total_data;
+}
+
+
+
 template <class StreamType>
 inline
 void
 Timer::print_data(StreamType &stream) const
 {
-  unsigned int my_id = dealii::Utilities::MPI::this_mpi_process(mpi_communicator);
-  if (my_id==0)
-    stream << mpi_data.max << " wall,"
-           << " max @" << mpi_data.max_index
-           << ", min=" << mpi_data.min << " @" << mpi_data.min_index
-           << ", avg=" << mpi_data.avg
-           << std::endl;
+  const Utilities::MPI::MinMaxAvg statistic = get_data();
+  stream << statistic.max << " wall,"
+         << " max @" << statistic.max_index << ", min=" << statistic.min << " @"
+         << statistic.min_index << ", avg=" << statistic.avg << std::endl;
+}
+
+
+
+template <class StreamType>
+inline
+void
+Timer::print_total_data(StreamType &stream) const
+{
+  const Utilities::MPI::MinMaxAvg statistic = get_total_data();
+  stream << statistic.max << " wall,"
+         << " max @" << statistic.max_index << ", min=" << statistic.min << " @"
+         << statistic.min_index << ", avg=" << statistic.avg << std::endl;
 }
 
 #endif
index 14bae115b578e73906083ec1368094b82902c2da..c7441509a664beedde7fab330910d19b710e3d95 100644 (file)
@@ -48,6 +48,7 @@ Timer::Timer()
   cumulative_time (0.),
   cumulative_wall_time (0.),
   last_lap_time (0.),
+  last_lap_cpu_time(0.),
   running (false)
 #ifdef DEAL_II_WITH_MPI
   ,
@@ -56,8 +57,10 @@ Timer::Timer()
 #endif
 {
 #ifdef DEAL_II_WITH_MPI
-  mpi_data.sum = mpi_data.min = mpi_data.max = mpi_data.avg = numbers::signaling_nan<double>();
-  mpi_data.min_index = mpi_data.max_index = numbers::invalid_unsigned_int;
+  mpi_data.sum = mpi_data.min = mpi_data.max = mpi_data.avg = 0.;
+  mpi_data.min_index = mpi_data.max_index = 0;
+  mpi_total_data.sum = mpi_total_data.min = mpi_total_data.max = mpi_total_data.avg = 0.;
+  mpi_total_data.min_index = mpi_total_data.max_index = 0;
 #endif
 
   start();
@@ -77,13 +80,16 @@ Timer::Timer(MPI_Comm mpi_communicator,
   cumulative_time (0.),
   cumulative_wall_time (0.),
   last_lap_time (0.),
+  last_lap_cpu_time (0.),
   running (false),
   mpi_communicator (mpi_communicator),
   sync_wall_time(sync_wall_time_)
 {
 #ifdef DEAL_II_WITH_MPI
-  mpi_data.sum = mpi_data.min = mpi_data.max = mpi_data.avg = numbers::signaling_nan<double>();
-  mpi_data.min_index = mpi_data.max_index = numbers::invalid_unsigned_int;
+  mpi_data.sum = mpi_data.min = mpi_data.max = mpi_data.avg = 0.;
+  mpi_data.min_index = mpi_data.max_index = 0;
+  mpi_total_data.sum = mpi_total_data.min = mpi_total_data.max = mpi_total_data.avg = 0.;
+  mpi_total_data.min_index = mpi_total_data.max_index = 0;
 #endif
 
   start();
@@ -175,13 +181,13 @@ double Timer::stop ()
       rusage usage;
       getrusage (RUSAGE_SELF, &usage);
       const double dtime = usage.ru_utime.tv_sec + 1.e-6 * usage.ru_utime.tv_usec;
-      cumulative_time += dtime - start_time;
+      last_lap_cpu_time = dtime - start_time;
 
       rusage usage_children;
       getrusage (RUSAGE_CHILDREN, &usage_children);
       const double dtime_children =
         usage_children.ru_utime.tv_sec + 1.e-6 * usage_children.ru_utime.tv_usec;
-      cumulative_time += dtime_children - start_time_children;
+      last_lap_cpu_time += dtime_children - start_time_children;
 
       struct timeval wall_timer;
       gettimeofday(&wall_timer, nullptr);
@@ -189,37 +195,34 @@ double Timer::stop ()
                       - start_wall_time;
 #elif defined(DEAL_II_MSVC)
       last_lap_time = windows::wall_clock() - start_wall_time;
-      cumulative_time += windows::cpu_clock() - start_time;
+      last_lap_cpu_time = windows::cpu_clock() - start_time;
 #else
 #  error Unsupported platform. Porting not finished.
 #endif
 
 #ifdef DEAL_II_WITH_MPI
+      this->mpi_data = Utilities::MPI::min_max_avg (last_lap_time,
+                                                    mpi_communicator);
       if (sync_wall_time && Utilities::MPI::job_supports_mpi())
         {
-          this->mpi_data
-            = Utilities::MPI::min_max_avg (last_lap_time, mpi_communicator);
           last_lap_time = this->mpi_data.max;
-          cumulative_wall_time += last_lap_time;
+          last_lap_cpu_time = Utilities::MPI::min_max_avg (last_lap_cpu_time,
+                                                           mpi_communicator).max;
         }
-      else
+      cumulative_wall_time += last_lap_time;
+      cumulative_time += last_lap_cpu_time;
+      this->mpi_total_data = Utilities::MPI::min_max_avg (cumulative_wall_time,
+                                                          mpi_communicator);
 #endif
-        cumulative_wall_time += last_lap_time;
+      cumulative_wall_time += last_lap_time;
+      cumulative_time += last_lap_cpu_time;
     }
   return cumulative_time;
 }
 
 
 
-double Timer::get_lap_time() const
-{
-  // time already has the difference between the last start()/stop() cycle.
-  return Utilities::MPI::max (last_lap_time, mpi_communicator);
-}
-
-
-
-double Timer::operator() () const
+double Timer::cpu_time() const
 {
   if (running)
     {
@@ -257,6 +260,27 @@ double Timer::operator() () const
 
 
 
+double Timer::last_cpu_time() const
+{
+  return last_lap_cpu_time;
+}
+
+
+
+double Timer::get_lap_time() const
+{
+  return last_lap_time;
+}
+
+
+
+double Timer::operator() () const
+{
+  return cpu_time();
+}
+
+
+
 double Timer::wall_time () const
 {
   if (running)
@@ -279,12 +303,26 @@ double Timer::wall_time () const
 
 
 
+double Timer::last_wall_time () const
+{
+  return last_lap_time;
+}
+
+
+
 void Timer::reset ()
 {
   last_lap_time = 0.;
+  last_lap_cpu_time = 0.;
   cumulative_time = 0.;
   cumulative_wall_time = 0.;
   running         = false;
+#ifdef DEAL_II_WITH_MPI
+  mpi_data.sum = mpi_data.min = mpi_data.max = mpi_data.avg = 0.;
+  mpi_data.min_index = mpi_data.max_index = 0;
+  mpi_total_data.sum = mpi_total_data.min = mpi_total_data.max = mpi_total_data.avg = 0.;
+  mpi_total_data.min_index = mpi_total_data.max_index = 0;
+#endif
 }
 
 
diff --git a/tests/base/timer_04.cc b/tests/base/timer_04.cc
new file mode 100644 (file)
index 0000000..8fc498b
--- /dev/null
@@ -0,0 +1,72 @@
+// ---------------------------------------------------------------------
+//
+// Copyright (C) 2017 by the deal.II authors
+//
+// This file is part of the deal.II library.
+//
+// The deal.II library is free software; you can use it, redistribute
+// it, and/or modify it under the terms of the GNU Lesser General
+// Public License as published by the Free Software Foundation; either
+// version 2.1 of the License, or (at your option) any later version.
+// The full text of the license can be found in the file LICENSE at
+// the top level of the deal.II distribution.
+//
+// ---------------------------------------------------------------------
+
+// the same as timer.cc but also test the new functions last_wall_time(),
+// cpu_time() and last_cpu_time().
+
+#include "../tests.h"
+#include <deal.II/base/timer.h>
+#include <deal.II/base/logstream.h>
+#include <fstream>
+#include <cmath>
+#include <iomanip>
+
+// burn computer time
+
+double s = 0.;
+void burn (unsigned int n)
+{
+  for (unsigned int i=0 ; i<n ; ++i)
+    {
+      for (unsigned int j=1 ; j<100000 ; ++j)
+        {
+          s += 1./j * i;
+        }
+    }
+}
+
+
+int main ()
+{
+  initlog();
+  deallog.threshold_double(1.e-10);
+
+  Timer t;
+  burn(50);
+
+  const double old_wall_time = t.wall_time();
+  AssertThrow(old_wall_time > 0., ExcInternalError());
+  const double old_cpu_time = t.wall_time();
+  AssertThrow(old_cpu_time > 0., ExcInternalError());
+  AssertThrow(t.last_wall_time() == 0., ExcInternalError());
+  AssertThrow(t.last_cpu_time() == 0, ExcInternalError());
+
+  burn(50);
+  AssertThrow(t.stop() > 0., ExcInternalError());
+
+  AssertThrow(t.wall_time() > old_wall_time, ExcInternalError());
+  AssertThrow(t.cpu_time() > old_cpu_time, ExcInternalError());
+  AssertThrow(t.last_wall_time() > 0., ExcInternalError());
+  AssertThrow(t.last_cpu_time() > 0, ExcInternalError());
+
+  t.reset();
+  AssertThrow(t.wall_time() == 0., ExcInternalError());
+  AssertThrow(t.cpu_time()== 0., ExcInternalError());
+  AssertThrow(t.last_wall_time() == 0., ExcInternalError());
+  AssertThrow(t.last_cpu_time() == 0, ExcInternalError());
+
+  deallog << "OK" << std::endl;
+}
+
diff --git a/tests/base/timer_04.output b/tests/base/timer_04.output
new file mode 100644 (file)
index 0000000..0fd8fc1
--- /dev/null
@@ -0,0 +1,2 @@
+
+DEAL::OK
diff --git a/tests/base/timer_05.cc b/tests/base/timer_05.cc
new file mode 100644 (file)
index 0000000..31a6e4a
--- /dev/null
@@ -0,0 +1,90 @@
+// ---------------------------------------------------------------------
+//
+// Copyright (C) 2017 by the deal.II authors
+//
+// This file is part of the deal.II library.
+//
+// The deal.II library is free software; you can use it, redistribute
+// it, and/or modify it under the terms of the GNU Lesser General
+// Public License as published by the Free Software Foundation; either
+// version 2.1 of the License, or (at your option) any later version.
+// The full text of the license can be found in the file LICENSE at
+// the top level of the deal.II distribution.
+//
+// ---------------------------------------------------------------------
+
+// the same as timer_04.cc but this time with MPI.
+
+#include "../tests.h"
+#include <deal.II/base/timer.h>
+#include <deal.II/base/logstream.h>
+#include <fstream>
+#include <cmath>
+#include <iomanip>
+
+// burn computer time
+
+double s = 0.;
+void burn (unsigned int n)
+{
+  for (unsigned int i=0 ; i<n ; ++i)
+    {
+      for (unsigned int j=1 ; j<100000 ; ++j)
+        {
+          s += 1./j * i;
+        }
+    }
+}
+
+
+
+void
+test_timer(Timer &t)
+{
+  burn(50);
+
+  const double old_wall_time = t.wall_time();
+  AssertThrow(old_wall_time > 0., ExcInternalError());
+  const double old_cpu_time = t.wall_time();
+  AssertThrow(old_cpu_time > 0., ExcInternalError());
+  AssertThrow(t.last_wall_time() == 0., ExcInternalError());
+  AssertThrow(t.last_cpu_time() == 0., ExcInternalError());
+  AssertThrow(t.get_data().min == 0., ExcInternalError());
+  AssertThrow(t.get_total_data().min == 0., ExcInternalError());
+
+  burn(50);
+  AssertThrow(t.stop() > 0., ExcInternalError());
+
+  AssertThrow(t.wall_time() > old_wall_time, ExcInternalError());
+  AssertThrow(t.cpu_time() > old_cpu_time, ExcInternalError());
+  AssertThrow(t.last_wall_time() > 0., ExcInternalError());
+  AssertThrow(t.last_cpu_time() > 0., ExcInternalError());
+  AssertThrow(t.get_data().min > 0., ExcInternalError());
+  AssertThrow(t.get_total_data().min > 0., ExcInternalError());
+
+  t.reset();
+  AssertThrow(t.wall_time() == 0., ExcInternalError());
+  AssertThrow(t.cpu_time()== 0., ExcInternalError());
+  AssertThrow(t.last_wall_time() == 0., ExcInternalError());
+  AssertThrow(t.last_cpu_time() == 0., ExcInternalError());
+  AssertThrow(t.get_data().min == 0., ExcInternalError());
+  AssertThrow(t.get_total_data().min == 0, ExcInternalError());
+
+  deallog << "OK" << std::endl;
+}
+
+
+
+int main (int argc, char **argv)
+{
+  Utilities::MPI::MPI_InitFinalize mpi_initialization(argc, argv, 1);
+  mpi_initlog();
+  deallog.threshold_double(1.e-10);
+
+  Timer t1(MPI_COMM_WORLD, false);
+  Timer t2(MPI_COMM_WORLD, true);
+
+  test_timer(t1);
+  test_timer(t2);
+}
+
diff --git a/tests/base/timer_05.with_mpi=true.mpirun=1.output b/tests/base/timer_05.with_mpi=true.mpirun=1.output
new file mode 100644 (file)
index 0000000..8b3b075
--- /dev/null
@@ -0,0 +1,3 @@
+
+DEAL::OK
+DEAL::OK

In the beginning the Universe was created. This has made a lot of people very angry and has been widely regarded as a bad move.

Douglas Adams


Typeset in Trocchi and Trocchi Bold Sans Serif.