18 #include "kmp_stats.h" 26 #define STRINGIZE2(x) #x 27 #define STRINGIZE(x) STRINGIZE2(x) 29 #define expandName(name,flags,ignore) {STRINGIZE(name),flags}, 30 statInfo timeStat::timerInfo[] = {
31 KMP_FOREACH_TIMER(expandName,0)
34 const statInfo counter::counterInfo[] = {
40 #define expandName(ignore1,ignore2,ignore3) {0.0,0.0,0.0}, 41 kmp_stats_output_module::rgb_color kmp_stats_output_module::timerColorInfo[] = {
42 KMP_FOREACH_TIMER(expandName,0)
47 const kmp_stats_output_module::rgb_color kmp_stats_output_module::globalColorArray[] = {
71 static uint32_t statsPrinted = 0;
74 static kmp_stats_output_module __kmp_stats_global_output;
79 void statistic::addSample(
double sample)
81 double delta = sample - meanVal;
83 sampleCount = sampleCount + 1;
84 meanVal = meanVal + delta/sampleCount;
85 m2 = m2 + delta*(sample - meanVal);
87 minVal = std::min(minVal, sample);
88 maxVal = std::max(maxVal, sample);
91 statistic & statistic::operator+= (
const statistic & other)
99 uint64_t newSampleCount = sampleCount + other.sampleCount;
100 double dnsc = double(newSampleCount);
101 double dsc = double(sampleCount);
102 double dscBydnsc = dsc/dnsc;
103 double dosc = double(other.sampleCount);
104 double delta = other.meanVal - meanVal;
111 meanVal = meanVal*dscBydnsc + other.meanVal*(1-dscBydnsc);
112 m2 = m2 + other.m2 + dscBydnsc*dosc*delta*delta;
113 minVal = std::min (minVal, other.minVal);
114 maxVal = std::max (maxVal, other.maxVal);
115 sampleCount = newSampleCount;
121 void statistic::scale(
double factor)
123 minVal = minVal*factor;
124 maxVal = maxVal*factor;
125 meanVal= meanVal*factor;
126 m2 = m2*factor*factor;
130 std::string statistic::format(
char unit,
bool total)
const 132 std::string result = formatSI(sampleCount,9,
' ');
134 if (sampleCount == 0)
136 result = result + std::string(
", ") + formatSI(0.0, 9, unit);
137 result = result + std::string(
", ") + formatSI(0.0, 9, unit);
138 result = result + std::string(
", ") + formatSI(0.0, 9, unit);
140 result = result + std::string(
", ") + formatSI(0.0, 9, unit);
141 result = result + std::string(
", ") + formatSI(0.0, 9, unit);
145 result = result + std::string(
", ") + formatSI(minVal, 9, unit);
146 result = result + std::string(
", ") + formatSI(meanVal, 9, unit);
147 result = result + std::string(
", ") + formatSI(maxVal, 9, unit);
149 result = result + std::string(
", ") + formatSI(meanVal*sampleCount, 9, unit);
150 result = result + std::string(
", ") + formatSI(getSD(), 9, unit);
158 void explicitTimer::start(timer_e timerEnumValue) {
159 startTime = tsc_tick_count::now();
162 __kmp_stats_thread_ptr->incrementNestValue();
167 void explicitTimer::stop(timer_e timerEnumValue) {
168 if (startTime.getValue() == 0)
171 tsc_tick_count finishTime = tsc_tick_count::now();
174 stat->addSample(((finishTime - startTime) - totalPauseTime).ticks());
177 __kmp_stats_thread_ptr->push_event(startTime.getValue() - __kmp_stats_start_time.getValue(), finishTime.getValue() - __kmp_stats_start_time.getValue(), __kmp_stats_thread_ptr->getNestValue(), timerEnumValue);
178 __kmp_stats_thread_ptr->decrementNestValue();
188 partitionedTimers::partitionedTimers() {
189 timer_stack.reserve(8);
193 void partitionedTimers::add_timer(explicit_timer_e timer_index, explicitTimer* timer_pointer) {
194 KMP_DEBUG_ASSERT((
int)timer_index < (
int)EXPLICIT_TIMER_LAST+1);
195 timers[timer_index] = timer_pointer;
199 void partitionedTimers::init(timerPair init_timer_pair) {
200 KMP_DEBUG_ASSERT(this->timer_stack.size() == 0);
201 timer_stack.push_back(init_timer_pair);
202 timers[init_timer_pair.get_index()]->start(init_timer_pair.get_timer());
209 void partitionedTimers::push(timerPair timer_pair) {
214 KMP_DEBUG_ASSERT(this->timer_stack.size() > 0);
215 timerPair current_timer = timer_stack.back();
216 timer_stack.push_back(timer_pair);
217 if(current_timer != timer_pair) {
218 timers[current_timer.get_index()]->pause();
219 timers[timer_pair.get_index()]->start(timer_pair.get_timer());
224 void partitionedTimers::pop() {
229 KMP_DEBUG_ASSERT(this->timer_stack.size() > 1);
230 timerPair current_timer = timer_stack.back();
231 timer_stack.pop_back();
232 timerPair new_timer = timer_stack.back();
233 if(current_timer != new_timer) {
234 timers[current_timer.get_index()]->stop(current_timer.get_timer());
235 timers[new_timer.get_index()]->resume();
243 void partitionedTimers::windup() {
244 while(timer_stack.size() > 1) {
247 if(timer_stack.size() > 0) {
248 timerPair last_timer = timer_stack.back();
249 timer_stack.pop_back();
250 timers[last_timer.get_index()]->stop(last_timer.get_timer());
257 void kmp_stats_event_vector::deallocate() {
268 int compare_two_events(
const void* event1,
const void* event2) {
269 kmp_stats_event* ev1 = (kmp_stats_event*)event1;
270 kmp_stats_event* ev2 = (kmp_stats_event*)event2;
272 if(ev1->getStart() < ev2->getStart())
return -1;
273 else if(ev1->getStart() > ev2->getStart())
return 1;
277 void kmp_stats_event_vector::sort() {
278 qsort(events, internal_size,
sizeof(kmp_stats_event), compare_two_events);
285 kmp_stats_list* kmp_stats_list::push_back(
int gtid) {
286 kmp_stats_list* newnode = (kmp_stats_list*)__kmp_allocate(
sizeof(kmp_stats_list));
288 new (newnode) kmp_stats_list();
289 newnode->setGtid(gtid);
290 newnode->prev = this->prev;
291 newnode->next =
this;
292 newnode->prev->next = newnode;
293 newnode->next->prev = newnode;
296 void kmp_stats_list::deallocate() {
297 kmp_stats_list* ptr = this->next;
298 kmp_stats_list* delptr = this->next;
303 delptr->_event_vector.deallocate();
304 delptr->~kmp_stats_list();
308 kmp_stats_list::iterator kmp_stats_list::begin() {
309 kmp_stats_list::iterator it;
313 kmp_stats_list::iterator kmp_stats_list::end() {
314 kmp_stats_list::iterator it;
318 int kmp_stats_list::size() {
320 kmp_stats_list::iterator it;
321 for(retval=0, it=begin(); it!=end(); it++, retval++) {}
328 kmp_stats_list::iterator::iterator() : ptr(NULL) {}
329 kmp_stats_list::iterator::~iterator() {}
330 kmp_stats_list::iterator kmp_stats_list::iterator::operator++() {
331 this->ptr = this->ptr->next;
334 kmp_stats_list::iterator kmp_stats_list::iterator::operator++(
int dummy) {
335 this->ptr = this->ptr->next;
338 kmp_stats_list::iterator kmp_stats_list::iterator::operator--() {
339 this->ptr = this->ptr->prev;
342 kmp_stats_list::iterator kmp_stats_list::iterator::operator--(
int dummy) {
343 this->ptr = this->ptr->prev;
346 bool kmp_stats_list::iterator::operator!=(
const kmp_stats_list::iterator & rhs) {
347 return this->ptr!=rhs.ptr;
349 bool kmp_stats_list::iterator::operator==(
const kmp_stats_list::iterator & rhs) {
350 return this->ptr==rhs.ptr;
352 kmp_stats_list* kmp_stats_list::iterator::operator*()
const {
359 const char* kmp_stats_output_module::eventsFileName = NULL;
360 const char* kmp_stats_output_module::plotFileName = NULL;
361 int kmp_stats_output_module::printPerThreadFlag = 0;
362 int kmp_stats_output_module::printPerThreadEventsFlag = 0;
365 void kmp_stats_output_module::init()
367 char * statsFileName = getenv(
"KMP_STATS_FILE");
368 eventsFileName = getenv(
"KMP_STATS_EVENTS_FILE");
369 plotFileName = getenv(
"KMP_STATS_PLOT_FILE");
370 char * threadStats = getenv(
"KMP_STATS_THREADS");
371 char * threadEvents = getenv(
"KMP_STATS_EVENTS");
378 std::string baseFileName, pid, suffix;
379 std::stringstream ss;
380 outputFileName = std::string(statsFileName);
381 index = outputFileName.find_last_of(
'.');
382 if(index == std::string::npos) {
383 baseFileName = outputFileName;
385 baseFileName = outputFileName.substr(0, index);
386 suffix = outputFileName.substr(index);
390 outputFileName = baseFileName +
"-" + pid + suffix;
392 eventsFileName = eventsFileName ? eventsFileName :
"events.dat";
393 plotFileName = plotFileName ? plotFileName :
"events.plt";
396 printPerThreadFlag = __kmp_str_match_true(threadStats);
397 printPerThreadEventsFlag = __kmp_str_match_true(threadEvents);
399 if(printPerThreadEventsFlag) {
404 timeStat::clearEventFlags();
410 void kmp_stats_output_module::setupEventColors() {
412 int globalColorIndex = 0;
413 int numGlobalColors =
sizeof(globalColorArray) /
sizeof(rgb_color);
414 for(i=0;i<TIMER_LAST;i++) {
416 timerColorInfo[i] = globalColorArray[globalColorIndex];
417 globalColorIndex = (globalColorIndex+1)%numGlobalColors;
423 void kmp_stats_output_module::printTimerStats(FILE *statsOut, statistic
const * theStats, statistic
const * totalStats)
425 fprintf (statsOut,
"Timer, SampleCount, Min, Mean, Max, Total, SD\n");
426 for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
427 statistic
const * stat = &theStats[s];
430 fprintf (statsOut,
"%-28s, %s\n", timeStat::name(s), stat->format(tag,
true).c_str());
433 for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
436 fprintf(statsOut,
"Total_%-22s, %s\n", timeStat::name(s), totalStats[s].format(tag,
true).c_str());
440 void kmp_stats_output_module::printCounterStats(FILE *statsOut, statistic
const * theStats)
442 fprintf (statsOut,
"Counter, ThreadCount, Min, Mean, Max, Total, SD\n");
443 for (
int s = 0; s<COUNTER_LAST; s++) {
444 statistic
const * stat = &theStats[s];
445 fprintf (statsOut,
"%-25s, %s\n", counter::name(counter_e(s)), stat->format(
' ',
true).c_str());
449 void kmp_stats_output_module::printCounters(FILE * statsOut, counter
const * theCounters)
453 fprintf (statsOut,
"\nCounter, Count\n");
454 for (
int c = 0; c<COUNTER_LAST; c++) {
455 counter
const * stat = &theCounters[c];
456 fprintf (statsOut,
"%-25s, %s\n", counter::name(counter_e(c)), formatSI(stat->getValue(), 9,
' ').c_str());
460 void kmp_stats_output_module::printEvents(FILE* eventsOut, kmp_stats_event_vector* theEvents,
int gtid) {
463 for (
int i = 0; i < theEvents->size(); i++) {
464 kmp_stats_event ev = theEvents->at(i);
465 rgb_color color = getEventColor(ev.getTimerName());
466 fprintf(eventsOut,
"%d %lu %lu %1.1f rgb(%1.1f,%1.1f,%1.1f) %s\n",
470 1.2 - (ev.getNestLevel() * 0.2),
471 color.r, color.g, color.b,
472 timeStat::name(ev.getTimerName())
478 void kmp_stats_output_module::windupExplicitTimers()
483 kmp_stats_list::iterator it;
484 for(it = __kmp_stats_list.begin(); it != __kmp_stats_list.end(); it++) {
485 kmp_stats_list* ptr = *it;
486 ptr->getPartitionedTimers()->windup();
487 for (
int timer=0; timer<EXPLICIT_TIMER_LAST; timer++) {
488 ptr->getExplicitTimer(explicit_timer_e(timer))->stop((timer_e)timer);
493 void kmp_stats_output_module::printPloticusFile() {
495 int size = __kmp_stats_list.size();
496 FILE* plotOut = fopen(plotFileName,
"w+");
498 fprintf(plotOut,
"#proc page\n" 502 fprintf(plotOut,
"#proc getdata\n" 506 fprintf(plotOut,
"#proc areadef\n" 507 " title: OpenMP Sampling Timeline\n" 508 " titledetails: align=center size=16\n" 509 " rectangle: 1 1 13 9\n" 510 " xautorange: datafield=2,3\n" 511 " yautorange: -1 %d\n\n",
514 fprintf(plotOut,
"#proc xaxis\n" 516 " stubdetails: size=12\n" 517 " label: Time (ticks)\n" 518 " labeldetails: size=14\n\n");
520 fprintf(plotOut,
"#proc yaxis\n" 523 " stubdetails: size=12\n" 525 " labeldetails: size=14\n\n",
528 fprintf(plotOut,
"#proc bars\n" 529 " exactcolorfield: 5\n" 532 " segmentfields: 2 3\n" 533 " barwidthfield: 4\n\n");
536 for(i=0;i<TIMER_LAST;i++) {
538 rgb_color c = getEventColor((timer_e)i);
539 fprintf(plotOut,
"#proc legendentry\n" 540 " sampletype: color\n" 542 " details: rgb(%1.1f,%1.1f,%1.1f)\n\n",
543 timeStat::name((timer_e)i),
549 fprintf(plotOut,
"#proc legend\n" 551 " location: max max\n\n");
562 void kmp_stats_output_module::printHeaderInfo(FILE * statsOut)
564 std::time_t now = std::time(0);
568 std::strftime(&buffer[0],
sizeof(buffer),
"%c", std::localtime(&now));
569 fprintf (statsOut,
"# Time of run: %s\n", &buffer[0]);
570 if (gethostname(&hostName[0],
sizeof(hostName)) == 0)
571 fprintf (statsOut,
"# Hostname: %s\n", &hostName[0]);
572 #if KMP_ARCH_X86 || KMP_ARCH_X86_64 573 fprintf (statsOut,
"# CPU: %s\n", &__kmp_cpuinfo.name[0]);
574 fprintf (statsOut,
"# Family: %d, Model: %d, Stepping: %d\n", __kmp_cpuinfo.family, __kmp_cpuinfo.model, __kmp_cpuinfo.stepping);
575 if (__kmp_cpuinfo.frequency == 0)
576 fprintf (statsOut,
"# Nominal frequency: Unknown\n");
578 fprintf (statsOut,
"# Nominal frequency: %sz\n", formatSI(
double(__kmp_cpuinfo.frequency),9,
'H').c_str());
582 void kmp_stats_output_module::outputStats(
const char* heading)
586 windupExplicitTimers();
588 statistic allStats[TIMER_LAST];
589 statistic totalStats[TIMER_LAST];
590 statistic allCounters[COUNTER_LAST];
592 FILE * statsOut = !outputFileName.empty() ? fopen (outputFileName.c_str(),
"a+") : stderr;
597 if (eventPrintingEnabled()) {
598 eventsOut = fopen(eventsFileName,
"w+");
601 printHeaderInfo (statsOut);
602 fprintf(statsOut,
"%s\n",heading);
604 kmp_stats_list::iterator it;
605 for (it = __kmp_stats_list.begin(); it != __kmp_stats_list.end(); it++) {
606 int t = (*it)->getGtid();
608 if (printPerThreadFlag) {
609 fprintf (statsOut,
"Thread %d\n", t);
610 printTimerStats (statsOut, (*it)->getTimers(), 0);
611 printCounters (statsOut, (*it)->getCounters());
612 fprintf (statsOut,
"\n");
615 if (eventPrintingEnabled()) {
616 kmp_stats_event_vector events = (*it)->getEventVector();
617 printEvents(eventsOut, &events, t);
621 for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
623 if ((timeStat::masterOnly(s) && (t != 0)) ||
624 (timeStat::workerOnly(s) && (t == 0))
630 statistic * threadStat = (*it)->getTimer(s);
631 allStats[s] += *threadStat;
635 totalStats[s].addSample(threadStat->getTotal());
639 for (counter_e c = counter_e(0); c<COUNTER_LAST; c = counter_e(c+1)) {
640 if (counter::masterOnly(c) && t != 0)
642 allCounters[c].addSample ((*it)->getCounter(c)->getValue());
646 if (eventPrintingEnabled()) {
651 fprintf (statsOut,
"Aggregate for all threads\n");
652 printTimerStats (statsOut, &allStats[0], &totalStats[0]);
653 fprintf (statsOut,
"\n");
654 printCounterStats (statsOut, &allCounters[0]);
656 if (statsOut != stderr)
666 void __kmp_reset_stats()
668 kmp_stats_list::iterator it;
669 for(it = __kmp_stats_list.begin(); it != __kmp_stats_list.end(); it++) {
670 timeStat * timers = (*it)->getTimers();
671 counter * counters = (*it)->getCounters();
672 explicitTimer * eTimers = (*it)->getExplicitTimers();
674 for (
int t = 0; t<TIMER_LAST; t++)
677 for (
int c = 0; c<COUNTER_LAST; c++)
680 for (
int t=0; t<EXPLICIT_TIMER_LAST; t++)
684 (*it)->resetEventVector();
689 void __kmp_output_stats(
const char * heading)
691 __kmp_stats_global_output.outputStats(heading);
695 void __kmp_accumulate_stats_at_exit(
void)
698 if (KMP_XCHG_FIXED32(&statsPrinted, 1) != 0)
701 __kmp_output_stats(
"Statistics on exit");
704 void __kmp_stats_init(
void)
do not show a TOTAL_aggregation for this statistic
statistic can be logged on the event timeline when KMP_STATS_EVENTS is on (valid only for timers) ...
statistic doesn't need units printed next to it in output
#define KMP_FOREACH_COUNTER(macro, arg)
Add new counters under KMP_FOREACH_COUNTER() macro in kmp_stats.h.