[STATS] Add a total statistics count which is an aggregation across all threads for each valid timers.

[jlpeyton]

Summary

This change removes synthesized stats and instead has all timers print out a total which is the aggregate statistics across threads. This is displayed as "Total_foo" at the end of program. The stats_flags_e::synthesized flag is removed and the printStats() function is split into two separate functions: printTimerStats() which can display the aggregate total and printCounterStats().

[jcownie]

Looks good to me.

openmp/trunk/runtime/src/kmp_stats.h

  * @ingroup STATS_GATHERING
  * \brief flags to describe the statistic ( timers or counter )
  *
 */
 class stats_flags_e {
     public:
         const static int onlyInMaster = 1<<0; //!< statistic is valid only for master
         const static int noUnits      = 1<<1; //!< statistic doesn't need units printed next to it in output
-        const static int synthesized  = 1<<2; //!< statistic's value is created atexit time in the __kmp_output_stats function
-        const static int notInMaster  = 1<<3; //!< statistic is valid for non-master threads
-        const static int logEvent     = 1<<4; //!< statistic can be logged when KMP_STATS_EVENTS is on (valid only for timers)
+        const static int notInMaster  = 1<<2; //!< statistic is valid for non-master threads
+        const static int logEvent     = 1<<3; //!< statistic can be logged when KMP_STATS_EVENTS is on (valid only for timers)
 };
 
 /*!
  * \brief Add new counters under KMP_FOREACH_COUNTER() macro in kmp_stats.h
  *
  * @param macro a user defined macro that takes three arguments - macro(COUNTER_NAME, flags, arg)
  * @param arg a user defined argument to send to the user defined macro
  *

  * \details A timer collects multiple samples of some count in each thread and then finally aggregates over all the threads.
  * The count is normally a time (in ticks), hence the name "timer". (But can be any value, so we use this for "number of arguments passed to fork"
  * as well).
  * For timers the threads are not significant, it's the individual observations that count, so the statistics are at that level.
  * Format is "macro(name, flags, arg)"
  *
  * @ingroup STATS_GATHERING2
  */
-#define KMP_FOREACH_TIMER(macro, arg)                                   \
-    macro (OMP_start_end, stats_flags_e::onlyInMaster, arg)             \
-    macro (OMP_serial, stats_flags_e::onlyInMaster, arg)                \
-    macro (OMP_work, 0, arg)                                            \
-    macro (Total_work, stats_flags_e::synthesized, arg)                 \
-    macro (OMP_barrier, 0, arg)                                         \
-    macro (Total_barrier, stats_flags_e::synthesized, arg)              \
-    macro (FOR_static_iterations, stats_flags_e::noUnits, arg)          \
-    macro (FOR_static_scheduling, 0, arg)                               \
-    macro (FOR_dynamic_iterations, stats_flags_e::noUnits, arg)         \
-    macro (FOR_dynamic_scheduling, 0, arg)                              \
-    macro (TASK_execution, 0, arg)                                      \
-    macro (OMP_set_numthreads, stats_flags_e::noUnits, arg)             \
-    macro (OMP_PARALLEL_args,  stats_flags_e::noUnits, arg)             \
-    macro (OMP_single, 0, arg)                                          \
-    macro (OMP_master, 0, arg)                                          \
-    KMP_FOREACH_DEVELOPER_TIMER(macro, arg)                             \
+#define KMP_FOREACH_TIMER(macro, arg)                           \
+    macro (OMP_start_end, stats_flags_e::onlyInMaster, arg)     \
+    macro (OMP_serial, stats_flags_e::onlyInMaster, arg)        \
+    macro (OMP_work, 0, arg)                                    \
+    macro (OMP_barrier, 0, arg)                                 \
+    macro (FOR_static_scheduling, 0, arg)                       \
+    macro (FOR_dynamic_scheduling, 0, arg)                      \
+    macro (TASK_execution, 0, arg)                              \
+    macro (OMP_single, 0, arg)                                  \
+    macro (OMP_master, 0, arg)                                  \
+    macro (OMP_set_numthreads, stats_flags_e::noUnits, arg)     \
+    macro (OMP_PARALLEL_args,  stats_flags_e::noUnits, arg)     \
+    macro (FOR_static_iterations, stats_flags_e::noUnits, arg)  \
+    macro (FOR_dynamic_iterations, stats_flags_e::noUnits, arg) \
+    KMP_FOREACH_DEVELOPER_TIMER(macro, arg)                     \
     macro (LAST,0, arg)
 
 
 // OMP_start_end          -- time from when OpenMP is initialized until the stats are printed at exit
 // OMP_serial             -- thread zero time executing serial code
 // OMP_work               -- elapsed time in code dispatched by a fork (measured in the thread)
-// Total_work             -- a synthesized statistic summarizing how much parallel work each thread executed.
-// OMP_barrier            -- time at "real" barriers
-// Total_barrier          -- a synthesized statistic summarizing how much time at real barriers in each thread
+// OMP_barrier            -- time at "real" barriers (includes task time)
+// TASK_execution         -- time spent executing tasks
+// FOR_static_iterations  -- Available parallelism in statically scheduled for loops
+// FOR_dynamic_iterations -- Available parallelism in dynamically scheduled for loops
 // FOR_static_scheduling  -- time spent doing scheduling for a static "for"
 // FOR_dynamic_scheduling -- time spent doing scheduling for a dynamic "for"
+// OMP_set_numthreads     -- Values passed to omp_set_num_threads
+// OMP_PARALLEL_args      -- Number of arguments passed to a parallel region
+// OMP_single
+
+
 
 #if (KMP_DEVELOPER_STATS)
 // Timers which are of interest tio runtime library developers, not end users.
 // THese have to be explicitly enabled in addition to the other stats.
 
 // KMP_fork_barrier       -- time in __kmp_fork_barrier
 // KMP_join_barrier       -- time in __kmp_join_barrier
 // KMP_barrier            -- time in __kmp_barrier
class timeStat : public statistic
     static statInfo timerInfo[];
 
  public:
     timeStat() : statistic() {}
     static const char * name(timer_e e) { return timerInfo[e].name; }
     static bool  masterOnly (timer_e e) { return timerInfo[e].flags & stats_flags_e::onlyInMaster; }
     static bool  workerOnly (timer_e e) { return timerInfo[e].flags & stats_flags_e::notInMaster;  }
     static bool  noUnits    (timer_e e) { return timerInfo[e].flags & stats_flags_e::noUnits;      }
-    static bool  synthesized(timer_e e) { return timerInfo[e].flags & stats_flags_e::synthesized;  }
     static bool  logEvent   (timer_e e) { return timerInfo[e].flags & stats_flags_e::logEvent;     }
     static void  clearEventFlags()      {
         int i;
         for(i=0;i<TIMER_LAST;i++) {
             timerInfo[i].flags &= (~(stats_flags_e::logEvent));
         }
     }
 };
private:
     static int printPerThreadFlag;
     static int printPerThreadEventsFlag;
     static const rgb_color globalColorArray[];
     static       rgb_color timerColorInfo[];
 
     void init();
     static void setupEventColors();
     static void printPloticusFile();
-    static void printStats(FILE *statsOut, statistic const * theStats, bool areTimers);
+    static void printTimerStats(FILE *statsOut, statistic const * theStats, statistic const * totalStats);
+    static void printCounterStats(FILE *statsOut, statistic const * theStats);
     static void printCounters(FILE * statsOut, counter const * theCounters);
     static void printEvents(FILE * eventsOut, kmp_stats_event_vector* theEvents, int gtid);
     static rgb_color getEventColor(timer_e e) { return timerColorInfo[e]; }
     static void windupExplicitTimers();
     bool eventPrintingEnabled() {
         if(printPerThreadEventsFlag) return true;
         else return false;
     }

openmp/trunk/runtime/src/kmp_stats.cpp

for(i=0;i<TIMER_LAST;i++) {
         if(timeStat::logEvent((timer_e)i)) {
             timerColorInfo[i] = globalColorArray[globalColorIndex];
             globalColorIndex = (globalColorIndex+1)%numGlobalColors;
         }
     }
     return;
 }
 
-void kmp_stats_output_module::printStats(FILE *statsOut, statistic const * theStats, bool areTimers)
+void kmp_stats_output_module::printTimerStats(FILE *statsOut, statistic const * theStats, statistic const * totalStats)
 {
-    if (areTimers)
-    {
-        // Check if we have useful timers, since we don't print zero value timers we need to avoid
-        // printing a header and then no data.
-        bool haveTimers = false;
-        for (int s = 0; s<TIMER_LAST; s++)
-        {
-            if (theStats[s].getCount() != 0)
-            {
-                haveTimers = true;
-                break;
-            }
-        }
-        if (!haveTimers)
-            return;
-    }
-
-    // Print
-    const char * title = areTimers ? "Timer,                   SampleCount," : "Counter,                 ThreadCount,";
-    fprintf (statsOut, "%s    Min,      Mean,       Max,     Total,        SD\n", title);    
-    if (areTimers) {
-        for (int s = 0; s<TIMER_LAST; s++) {
-            statistic const * stat = &theStats[s];
-            if (stat->getCount() != 0) {
-                char tag = timeStat::noUnits(timer_e(s)) ? ' ' : 'T';
-                fprintf (statsOut, "%-25s, %s\n", timeStat::name(timer_e(s)), stat->format(tag, true).c_str());
-            }
-        }
-    } else {   // Counters
-        for (int s = 0; s<COUNTER_LAST; s++) {
-            statistic const * stat = &theStats[s];
-            fprintf (statsOut, "%-25s, %s\n", counter::name(counter_e(s)), stat->format(' ', true).c_str());
-        }
-    }
-} 
+    fprintf (statsOut, "Timer,                      SampleCount,    Min,      Mean,       Max,     Total,        SD\n");
+
+        fprintf (statsOut, "%-28s, %s\n", timeStat::name(timer_e(s)), stat->format(tag, true).c_str());
+        // Also print the Total_ versions of times.
+        if (totalStats && tag == 'T' && !timeStat::masterOnly(timer_e(s))) {
+            fprintf(statsOut, "Total_%-22s, %s\n", timeStat::name(timer_e(s)), totalStats[s].format(tag, true).c_str());
+}
+
+void kmp_stats_output_module::printCounterStats(FILE *statsOut, statistic const * theStats)
+{
+    fprintf (statsOut, "Counter,                 ThreadCount,    Min,      Mean,       Max,     Total,        SD\n");
 
 void kmp_stats_output_module::printCounters(FILE * statsOut, counter const * theCounters)
 {
     // We print all the counters even if they are zero.
     // That makes it easier to slice them into a spreadsheet if you need to.
     fprintf (statsOut, "\nCounter,                    Count\n");
     for (int c = 0; c<COUNTER_LAST; c++) {
         counter const * stat = &theCounters[c];
fprintf(plotOut, "#proc legend\n"
                      "   location: max max\n\n");
     fclose(plotOut);
     return;
 }
 
 void kmp_stats_output_module::outputStats(const char* heading) 
 {
     statistic allStats[TIMER_LAST];
+    statistic totalStats[TIMER_LAST];           /* Synthesized, cross threads versions of normal timer stats */
     statistic allCounters[COUNTER_LAST];
 
     // stop all the explicit timers for all threads
     windupExplicitTimers();
 
     FILE * eventsOut;
     FILE * statsOut = outputFileName ? fopen (outputFileName, "a+") : stderr;
 
     if (eventPrintingEnabled()) {
         eventsOut = fopen(eventsFileName, "w+");
     }
 
     if (!statsOut)
         statsOut = stderr;
 
     fprintf(statsOut, "%s\n",heading);
     // Accumulate across threads.
     kmp_stats_list::iterator it;
     for (it = __kmp_stats_list.begin(); it != __kmp_stats_list.end(); it++) {
         int t = (*it)->getGtid();
         // Output per thread stats if requested.
         if (perThreadPrintingEnabled()) {
             fprintf (statsOut, "Thread %d\n", t);
-            printStats(statsOut, (*it)->getTimers(), true);
+            printTimerStats(statsOut, (*it)->getTimers(), 0);
             printCounters(statsOut, (*it)->getCounters());
             fprintf(statsOut,"\n");
         }
         // Output per thread events if requested.
         if (eventPrintingEnabled()) {
             kmp_stats_event_vector events = (*it)->getEventVector();
             printEvents(eventsOut, &events, t);
         }
 
+        // Accumulate timers.
         for (int s = 0; s<TIMER_LAST; s++) {
             // See if we should ignore this timer when aggregating
             if ((timeStat::masterOnly(timer_e(s)) && (t != 0)) || // Timer is only valid on the master and this thread is a worker
-                (timeStat::workerOnly(timer_e(s)) && (t == 0)) || // Timer is only valid on a worker and this thread is the master
-                timeStat::synthesized(timer_e(s))                 // It's a synthesized stat, so there's no raw data for it.
+                (timeStat::workerOnly(timer_e(s)) && (t == 0))    // Timer is only valid on a worker and this thread is the master
                )            
             {
                 continue;
             }
 
             statistic * threadStat = (*it)->getTimer(timer_e(s));
             allStats[s] += *threadStat;
-        }
 
-        // Special handling for synthesized statistics.
-        // These just have to be coded specially here for now. 
-        // At present we only have a few: 
-        // The total parallel work done in each thread.
-        // The variance here makes it easy to see load imbalance over the whole program (though, of course,
-        // it's possible to have a code with awful load balance in every parallel region but perfect load
-        // balance oever the whole program.)
-        // The time spent in barriers in each thread.
-        allStats[TIMER_Total_work].addSample ((*it)->getTimer(TIMER_OMP_work)->getTotal());
-
-        // Time in explicit barriers.
-        allStats[TIMER_Total_barrier].addSample ((*it)->getTimer(TIMER_OMP_barrier)->getTotal());
+            // Add Total stats for all real times (not counts) that are valid in more than one thread
+            if (!timeStat::noUnits(timer_e(s)) && !timeStat::masterOnly(timer_e(s)))
+            {
+                totalStats[s].addSample(threadStat->getTotal());
+            }
+        }
 
+        // Accumulate counters.
         for (int c = 0; c<COUNTER_LAST; c++) {
             if (counter::masterOnly(counter_e(c)) && t != 0)
                 continue;
             allCounters[c].addSample ((*it)->getCounter(counter_e(c))->getValue());
         }
     }
 
     if (eventPrintingEnabled()) {
         printPloticusFile();
         fclose(eventsOut);
     }
 
     fprintf (statsOut, "Aggregate for all threads\n");
-    printStats (statsOut, &allStats[0], true);
+    printTimerStats (statsOut, &allStats[0], &totalStats[0]);
     fprintf (statsOut, "\n");
-    printStats (statsOut, &allCounters[0], false);
+    printCounterStats (statsOut, &allCounters[0]);
 
     if (statsOut != stderr)
         fclose(statsOut);
 
 }
 
 /* ************************************************** */
 /* *************  exported C functions ************** */