Carpet: More work on timers

Store physical timing information in grid scalars for easier output.

Introduce a parameter "Carpet::silent" to switch off periodic output
of the physical timing information.

Add detailed timers for Carpet's main evolution loop, using Cactus
timers.  Their output would usually be written to files.

darcs-hash:20060727165144-dae7b-aac1f402b3d23351153dfa8b48ee52a29d05e94e.gz

1 files changed, 157 insertions, 15 deletions

diff --git a/Carpet/Carpet/src/Evolve.cc b/Carpet/Carpet/src/Evolve.cc
index 6006303f6..06bd88038 100644
--- a/Carpet/Carpet/src/Evolve.cc
+++ b/Carpet/Carpet/src/Evolve.cc
@@ -1,10 +1,13 @@
 #include <cassert>
+#include <cstdio>
 #include <cstdlib>
 
 #include "cctk.h"
 #include "cctk_Parameters.h"
 #include "cctk_Termination.h"
 
+#include "util_String.h"
+
 // IRIX wants this before <time.h>
 #if HAVE_SYS_TYPES_H
 #  include <sys/types.h>
@@ -22,6 +25,7 @@
 #endif
 
 #if HAVE_UNISTD_H
+#  include <fcntl.h>
 #  include <unistd.h>
 #endif
 
@@ -38,6 +42,18 @@ namespace Carpet {
 
 
 
+  static int evolve_timer            ;
+  static int do_terminate_timer      ;
+  static int advance_time_timer      ;
+  static int preregrid_timer         ;
+  static int regrid_timer            ;
+  static int postregrid_timer        ;
+  static int evolution_i_timer       ;
+  static int evolution_restrict_timer;
+  static int evolution_ii_timer      ;
+
+
+
   static bool do_terminate (const cGH *cgh,
                             const CCTK_REAL time, const int iteration)
   {
@@ -135,13 +151,32 @@ namespace Carpet {
     const int convlev = 0;
     cGH* cgh = fc->GH[convlev];
 
+    // Create timers
+    evolve_timer             = CCTK_TimerCreate ("Carpet::Evolve"           );
+    do_terminate_timer       = CCTK_TimerCreate ("Carpet::do_terminate"     );
+    advance_time_timer       = CCTK_TimerCreate ("Carpet::AdvanceTime"      );
+    preregrid_timer          = CCTK_TimerCreate ("Carpet::PreRegrid"        );
+    regrid_timer             = CCTK_TimerCreate ("Carpet::Regrid"           );
+    postregrid_timer         = CCTK_TimerCreate ("Carpet::PostRegrid"       );
+    evolution_i_timer        = CCTK_TimerCreate ("Carpet::EvolutionI"       );
+    evolution_restrict_timer = CCTK_TimerCreate ("Carpet::EvolutionRestrict");
+    evolution_ii_timer       = CCTK_TimerCreate ("Carpet::EvolutionII"      );
+
     // Timing statistics
     InitTiming (cgh);
 
     // Main loop
-    while (! do_terminate(cgh, cgh->cctk_time, cgh->cctk_iteration)) {
-
+    CCTK_TimerStartI (evolve_timer);
+    for (;;) {
+      CCTK_TimerStartI (do_terminate_timer);
+      bool const do_term =
+        do_terminate (cgh, cgh->cctk_time, cgh->cctk_iteration);
+      CCTK_TimerStopI (do_terminate_timer);
+      if (do_term) break;
+
+      CCTK_TimerStartI (advance_time_timer);
       AdvanceTime( cgh, cctk_initial_time );
+      CCTK_TimerStopI (advance_time_timer);
 
       if ((cgh->cctk_iteration-1)
           % (maxtimereflevelfact / timereffacts.at(reflevels-1)) == 0) {
@@ -149,16 +184,31 @@ namespace Carpet {
                   cgh->cctk_iteration, (double)cgh->cctk_time);
       }
 
-      PreRegrid( cgh );
-
-      if( Regrid( cgh ) )
-        PostRegrid( cgh );
+      CCTK_TimerStartI (preregrid_timer);
+      PreRegrid (cgh);
+      CCTK_TimerStopI (preregrid_timer);
+
+      CCTK_TimerStartI (regrid_timer);
+      bool const did_regrid = Regrid (cgh);
+      CCTK_TimerStopI (regrid_timer);
+      
+      if (did_regrid) {
+        CCTK_TimerStartI (postregrid_timer);
+        PostRegrid (cgh);
+        CCTK_TimerStopI (postregrid_timer);
+      }
 
-      EvolutionI( cgh );
+      CCTK_TimerStartI (evolution_i_timer);
+      EvolutionI (cgh);
+      CCTK_TimerStopI (evolution_i_timer);
 
-      Evolution_Restrict( cgh );
+      CCTK_TimerStartI (evolution_restrict_timer);
+      Evolution_Restrict (cgh);
+      CCTK_TimerStopI (evolution_restrict_timer);
 
-      EvolutionII( cgh );
+      CCTK_TimerStartI (evolution_ii_timer);
+      EvolutionII (cgh);
+      CCTK_TimerStopI (evolution_ii_timer);
 
       if (output_internal_data) {
         CCTK_INFO ("Internal data dump:");
@@ -170,7 +220,94 @@ namespace Carpet {
         cout.precision (oldprecision);
       }
 
-    }
+      if ((cgh->cctk_iteration - 1) %
+          (maxtimereflevelfact / timereffacts.at(reflevels - 1)) == 0 and
+          output_timers_every > 0 and
+          (cgh->cctk_iteration - 1) % output_timers_every == 0)
+      {
+        // Print timer values
+        
+        int fdsave;
+        if (not CCTK_EQUALS (timer_file, "")) {
+#ifndef HAVE_UNISTD_H
+          CCTK_WARN (1, "Cannot redirect timer output to a file; the operating system does not support this");
+#else // #ifdef HAVE_UNISTD_H
+          
+          int const myproc = CCTK_MyProc (cgh);
+          char filename [10000];
+          Util_snprintf (filename, sizeof filename,
+                         "%s/%s.%04d.txt", out_dir, timer_file, myproc);
+          
+          // append
+          int flags = O_WRONLY | O_CREAT | O_APPEND;
+          static bool first_time = true;
+          if (first_time) {
+            first_time = false;
+            if (IO_TruncateOutputFiles (cgh)) {
+              // truncate
+              flags = O_WRONLY | O_CREAT | O_TRUNC;
+            }
+          }
+          
+          // Temporarily redirect stdout
+          fflush (stdout);
+          fdsave = dup (1);      // fd 1 is stdout
+          int const mode = 0644; // rw-r--r--, or a+r u+w
+          int const fdfile = open (filename, flags, mode);
+          if (fdfile < 0)
+          {
+            CCTK_VWarn (1, __LINE__, __FILE__, CCTK_THORNSTRING,
+                        "Could not open timer output file \"%s\"", filename);
+            goto cleanup;
+          }
+          close (1);
+          dup (fdfile);         // dup to 1, i.e., stdout again
+          close (fdfile);
+#endif  // #ifdef HAVE_UNISTD_H
+        }
+        
+        // Output the timers
+        printf ("Carpet Timing information at iteration %d time %g:\n",
+                cgh->cctk_iteration, (double) cgh->cctk_time);
+        CCTK_TimerStopI (evolve_timer);
+        CCTK_TimerPrintDataI (evolve_timer            , -1);
+        CCTK_TimerPrintDataI (do_terminate_timer      , -1);
+        CCTK_TimerPrintDataI (advance_time_timer      , -1);
+        CCTK_TimerPrintDataI (preregrid_timer         , -1);
+        CCTK_TimerPrintDataI (regrid_timer            , -1);
+        CCTK_TimerPrintDataI (postregrid_timer        , -1);
+        CCTK_TimerPrintDataI (evolution_i_timer       , -1);
+        CCTK_TimerPrintDataI (evolution_restrict_timer, -1);
+        CCTK_TimerPrintDataI (evolution_ii_timer      , -1);
+        CCTK_TimerStartI (evolve_timer);
+        printf ("\n********************************************************************************\n");
+        
+        if (not CCTK_EQUALS (timer_file, "")) {
+#ifdef HAVE_UNISTD_H
+          // Redirect stdout back
+          fflush (stdout);
+          close (1);
+          dup (fdsave);
+        cleanup:
+          close (fdsave);
+#endif  // #ifdef HAVE_UNISTD_H
+        }
+        
+      } // if timer output
+
+    } // end main loop
+    CCTK_TimerStopI (evolve_timer);
+
+    // Destroy timers
+    CCTK_TimerDestroyI (evolve_timer            );
+    CCTK_TimerDestroyI (do_terminate_timer      );
+    CCTK_TimerDestroyI (advance_time_timer      );
+    CCTK_TimerDestroyI (preregrid_timer         );
+    CCTK_TimerDestroyI (regrid_timer            );
+    CCTK_TimerDestroyI (postregrid_timer        );
+    CCTK_TimerDestroyI (evolution_i_timer       );
+    CCTK_TimerDestroyI (evolution_restrict_timer);
+    CCTK_TimerDestroyI (evolution_ii_timer      );
 
     Waypoint ("Done with evolution loop");
 
@@ -359,6 +496,8 @@ namespace Carpet {
 
   void EvolutionII( cGH* cgh )
   {
+    DECLARE_CCTK_PARAMETERS;
+
     for (int ml=mglevels-1; ml>=0; --ml) {
 
       bool have_done_global_mode = false;
@@ -422,6 +561,14 @@ namespace Carpet {
           // Checking
           CheckChecksums (cgh, alltimes);
 
+          if (do_global_mode and
+              print_timestats_every > 0 and
+              cgh->cctk_iteration % print_timestats_every == 0)
+          {
+            // Timing statistics
+            PrintTimingStats (cgh);
+          }
+
           leave_level_mode (cgh);
           leave_global_mode (cgh);
         }
@@ -430,11 +577,6 @@ namespace Carpet {
       if (have_done_anything)
         assert (have_done_global_mode);
 
-      if (have_done_anything) {
-        // Timing statistics
-        PrintTimingStats (cgh);
-      }
-
     }
 
   }