[STATS] Add header information to stats print out

This change adds a header to the printout of the statistics which includes the
time, machine name, and processor info if available. This change also includes
some cosmetic changes like using enum casting for timer and counter iteration.

Differential Revision: http://reviews.llvm.org/D18153

llvm-svn: 263580
This commit is contained in:
Jonathan Peyton 2016-03-15 20:28:47 +00:00
parent d6e91369d8
commit 6e98d7988b
4 changed files with 69 additions and 61 deletions

View File

@ -1241,6 +1241,7 @@ typedef struct kmp_cpuinfo {
int physical_id;
int logical_id;
kmp_uint64 frequency; // Nominal CPU frequency in Hz.
char name [3*sizeof (kmp_cpuid_t)]; // CPUID(0x80000002,0x80000003,0x80000004)
} kmp_cpuinfo_t;

View File

@ -21,6 +21,7 @@
#include <sstream>
#include <iomanip>
#include <stdlib.h> // for atexit
#include <ctime>
#define STRINGIZE2(x) #x
#define STRINGIZE(x) STRINGIZE2(x)
@ -337,15 +338,14 @@ void kmp_stats_output_module::setupEventColors() {
void kmp_stats_output_module::printTimerStats(FILE *statsOut, statistic const * theStats, statistic const * totalStats)
{
fprintf (statsOut, "Timer, SampleCount, Min, Mean, Max, Total, SD\n");
for (int s = 0; s<TIMER_LAST; s++) {
for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
statistic const * stat = &theStats[s];
char tag = timeStat::noUnits(s) ? ' ' : 'T';
char tag = timeStat::noUnits(timer_e(s)) ? ' ' : 'T';
fprintf (statsOut, "%-28s, %s\n", timeStat::name(timer_e(s)), stat->format(tag, true).c_str());
fprintf (statsOut, "%-28s, %s\n", timeStat::name(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());
}
if (totalStats && !timeStat::noTotal(s))
fprintf(statsOut, "Total_%-22s, %s\n", timeStat::name(s), totalStats[s].format(tag, true).c_str());
}
}
@ -463,36 +463,60 @@ void kmp_stats_output_module::printPloticusFile() {
return;
}
/*
* Print some useful information about
* * the date and time this experiment ran.
* * the machine on which it ran.
* We output all of this as stylised comments, though we may decide to parse some of it.
*/
void kmp_stats_output_module::printHeaderInfo(FILE * statsOut)
{
std::time_t now = std::time(0);
char buffer[40];
char hostName[80];
std::strftime(&buffer[0], sizeof(buffer), "%c", std::localtime(&now));
fprintf (statsOut, "# Time of run: %s\n", &buffer[0]);
if (gethostname(&hostName[0], sizeof(hostName)) == 0)
fprintf (statsOut,"# Hostname: %s\n", &hostName[0]);
#if KMP_ARCH_X86 || KMP_ARCH_X86_64
fprintf (statsOut, "# CPU: %s\n", &__kmp_cpuinfo.name[0]);
fprintf (statsOut, "# Family: %d, Model: %d, Stepping: %d\n", __kmp_cpuinfo.family, __kmp_cpuinfo.model, __kmp_cpuinfo.stepping);
fprintf (statsOut, "# Nominal frequency: %sz\n", formatSI(double(__kmp_cpuinfo.frequency),9,'H').c_str());
#endif
}
void kmp_stats_output_module::outputStats(const char* heading)
{
// Stop all the explicit timers in all threads
// Do this before declaring the local statistics because thay have constructors so will take time to create.
windupExplicitTimers();
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 * statsOut = outputFileName ? fopen (outputFileName, "a+") : stderr;
if (!statsOut)
statsOut = stderr;
FILE * eventsOut;
FILE * statsOut = outputFileName ? fopen (outputFileName, "a+") : stderr;
if (eventPrintingEnabled()) {
eventsOut = fopen(eventsFileName, "w+");
}
if (!statsOut)
statsOut = stderr;
printHeaderInfo (statsOut);
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()) {
if (printPerThreadFlag) {
fprintf (statsOut, "Thread %d\n", t);
printTimerStats(statsOut, (*it)->getTimers(), 0);
printCounters(statsOut, (*it)->getCounters());
fprintf(statsOut,"\n");
printTimerStats (statsOut, (*it)->getTimers(), 0);
printCounters (statsOut, (*it)->getCounters());
fprintf (statsOut,"\n");
}
// Output per thread events if requested.
if (eventPrintingEnabled()) {
@ -501,30 +525,28 @@ void kmp_stats_output_module::outputStats(const char* heading)
}
// Accumulate timers.
for (int s = 0; s<TIMER_LAST; s++) {
for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
// 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
if ((timeStat::masterOnly(s) && (t != 0)) || // Timer is only valid on the master and this thread is a worker
(timeStat::workerOnly(s) && (t == 0)) // Timer is only valid on a worker and this thread is the master
)
{
continue;
}
statistic * threadStat = (*it)->getTimer(timer_e(s));
statistic * threadStat = (*it)->getTimer(s);
allStats[s] += *threadStat;
// 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)))
{
// Add Total stats for timers that are valid in more than one thread
if (!timeStat::noTotal(s))
totalStats[s].addSample(threadStat->getTotal());
}
}
// Accumulate counters.
for (int c = 0; c<COUNTER_LAST; c++) {
if (counter::masterOnly(counter_e(c)) && t != 0)
for (counter_e c = counter_e(0); c<COUNTER_LAST; c = counter_e(c+1)) {
if (counter::masterOnly(c) && t != 0)
continue;
allCounters[c].addSample ((*it)->getCounter(counter_e(c))->getValue());
allCounters[c].addSample ((*it)->getCounter(c)->getValue());
}
}
@ -540,7 +562,6 @@ void kmp_stats_output_module::outputStats(const char* heading)
if (statsOut != stderr)
fclose(statsOut);
}
/* ************************************************** */
@ -589,12 +610,10 @@ void __kmp_accumulate_stats_at_exit(void)
return;
__kmp_output_stats("Statistics on exit");
return;
}
void __kmp_stats_init(void)
{
return;
}
} // extern "C"

View File

@ -43,12 +43,12 @@
* \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 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)
enum stats_flags_e {
noTotal = 1<<0, //!< do not show a TOTAL_aggregation for this statistic
onlyInMaster = (1<<1) | noTotal, //!< statistic is valid only for master
noUnits = (1<<2) | noTotal, //!< statistic doesn't need units printed next to it in output
notInMaster = 1<<3, //!< statistic is valid only for non-master threads
logEvent = 1<<4 //!< statistic can be logged when KMP_STATS_EVENTS is on (valid only for timers)
};
/*!
@ -99,7 +99,8 @@ class stats_flags_e {
* @param macro a user defined macro that takes three arguments - macro(TIMER_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.
* \details A timer collects multiple samples of some count in each thread and then finally aggregates alll of the samples from all of the threads.
* For most timers the printing code also provides an aggregation over the thread totals. These are printed as TOTAL_foo.
* 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.
@ -276,13 +277,13 @@ class timeStat : public statistic
public:
timeStat() : statistic() {}
static const char * name(timer_e e) { return timerInfo[e].name; }
static bool noTotal (timer_e e) { return timerInfo[e].flags & stats_flags_e::noTotal; }
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 logEvent (timer_e e) { return timerInfo[e].flags & stats_flags_e::logEvent; }
static void clearEventFlags() {
int i;
for(i=0;i<TIMER_LAST;i++) {
for(int i=0;i<TIMER_LAST;i++) {
timerInfo[i].flags &= (~(stats_flags_e::logEvent));
}
}
@ -575,20 +576,14 @@ class kmp_stats_output_module {
void init();
static void setupEventColors();
static void printPloticusFile();
static void printHeaderInfo(FILE *statsOut);
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;
}
bool perThreadPrintingEnabled() {
if(printPerThreadFlag) return true;
else return false;
}
bool eventPrintingEnabled() const { return printPerThreadEventsFlag; }
public:
kmp_stats_output_module() { init(); }

View File

@ -279,26 +279,19 @@ __kmp_query_cpuid( kmp_cpuinfo_t *p )
#endif
}; // if
{ // Parse CPU brand string for frequency.
union kmp_cpu_brand_string {
struct kmp_cpuid buf[ 3 ];
char string[ sizeof( struct kmp_cpuid ) * 3 + 1 ];
}; // union kmp_cpu_brand_string
union kmp_cpu_brand_string brand;
{ // Parse CPU brand string for frequency, saving the string for later.
int i;
p->frequency = 0;
kmp_cpuid_t * base = (kmp_cpuid_t *)&p->name[0];
// Get CPU brand string.
for ( i = 0; i < 3; ++ i ) {
__kmp_x86_cpuid( 0x80000002 + i, 0, &brand.buf[ i ] );
__kmp_x86_cpuid( 0x80000002 + i, 0, base+i );
}; // for
brand.string[ sizeof( brand.string ) - 1 ] = 0; // Just in case. ;-)
KA_TRACE( trace_level, ( "cpu brand string: \"%s\"\n", brand.string ) );
p->name[ sizeof(p->name) - 1 ] = 0; // Just in case. ;-)
KA_TRACE( trace_level, ( "cpu brand string: \"%s\"\n", &p->name[0] ) );
// Parse frequency.
p->frequency = __kmp_parse_frequency( strrchr( brand.string, ' ' ) );
p->frequency = __kmp_parse_frequency( strrchr( &p->name[0], ' ' ) );
KA_TRACE( trace_level, ( "cpu frequency from brand string: %" KMP_UINT64_SPEC "\n", p->frequency ) );
}
}