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 = NULL;
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, kmp_stats_list* stats_ptr ) {
168 if (startTime.getValue() == 0)
171 tsc_tick_count finishTime = tsc_tick_count::now();
174 stat->addSample(((finishTime - startTime) - totalPauseTime).ticks());
178 stats_ptr = __kmp_stats_thread_ptr;
179 stats_ptr->push_event(startTime.getValue() - __kmp_stats_start_time.getValue(), finishTime.getValue() - __kmp_stats_start_time.getValue(), __kmp_stats_thread_ptr->getNestValue(), timerEnumValue);
180 stats_ptr->decrementNestValue();
190 partitionedTimers::partitionedTimers() {
191 timer_stack.reserve(8);
195 void partitionedTimers::add_timer(explicit_timer_e timer_index, explicitTimer* timer_pointer) {
196 KMP_DEBUG_ASSERT((
int)timer_index < (
int)EXPLICIT_TIMER_LAST+1);
197 timers[timer_index] = timer_pointer;
201 void partitionedTimers::init(timerPair init_timer_pair) {
202 KMP_DEBUG_ASSERT(this->timer_stack.size() == 0);
203 timer_stack.push_back(init_timer_pair);
204 timers[init_timer_pair.get_index()]->start(init_timer_pair.get_timer());
211 void partitionedTimers::push(timerPair timer_pair) {
216 KMP_DEBUG_ASSERT(this->timer_stack.size() > 0);
217 timerPair current_timer = timer_stack.back();
218 timer_stack.push_back(timer_pair);
219 if(current_timer != timer_pair) {
220 timers[current_timer.get_index()]->pause();
221 timers[timer_pair.get_index()]->start(timer_pair.get_timer());
226 void partitionedTimers::pop() {
231 KMP_DEBUG_ASSERT(this->timer_stack.size() > 1);
232 timerPair current_timer = timer_stack.back();
233 timer_stack.pop_back();
234 timerPair new_timer = timer_stack.back();
235 if(current_timer != new_timer) {
236 timers[current_timer.get_index()]->stop(current_timer.get_timer());
237 timers[new_timer.get_index()]->resume();
245 void partitionedTimers::windup() {
246 while(timer_stack.size() > 1) {
249 if(timer_stack.size() > 0) {
250 timerPair last_timer = timer_stack.back();
251 timer_stack.pop_back();
252 timers[last_timer.get_index()]->stop(last_timer.get_timer());
259 void kmp_stats_event_vector::deallocate() {
270 int compare_two_events(
const void* event1,
const void* event2) {
271 kmp_stats_event* ev1 = (kmp_stats_event*)event1;
272 kmp_stats_event* ev2 = (kmp_stats_event*)event2;
274 if(ev1->getStart() < ev2->getStart())
return -1;
275 else if(ev1->getStart() > ev2->getStart())
return 1;
279 void kmp_stats_event_vector::sort() {
280 qsort(events, internal_size,
sizeof(kmp_stats_event), compare_two_events);
287 kmp_stats_list* kmp_stats_list::push_back(
int gtid) {
288 kmp_stats_list* newnode = (kmp_stats_list*)__kmp_allocate(
sizeof(kmp_stats_list));
290 new (newnode) kmp_stats_list();
291 newnode->setGtid(gtid);
292 newnode->prev = this->prev;
293 newnode->next =
this;
294 newnode->prev->next = newnode;
295 newnode->next->prev = newnode;
298 void kmp_stats_list::deallocate() {
299 kmp_stats_list* ptr = this->next;
300 kmp_stats_list* delptr = this->next;
305 delptr->_event_vector.deallocate();
306 delptr->~kmp_stats_list();
310 kmp_stats_list::iterator kmp_stats_list::begin() {
311 kmp_stats_list::iterator it;
315 kmp_stats_list::iterator kmp_stats_list::end() {
316 kmp_stats_list::iterator it;
320 int kmp_stats_list::size() {
322 kmp_stats_list::iterator it;
323 for(retval=0, it=begin(); it!=end(); it++, retval++) {}
330 kmp_stats_list::iterator::iterator() : ptr(NULL) {}
331 kmp_stats_list::iterator::~iterator() {}
332 kmp_stats_list::iterator kmp_stats_list::iterator::operator++() {
333 this->ptr = this->ptr->next;
336 kmp_stats_list::iterator kmp_stats_list::iterator::operator++(
int dummy) {
337 this->ptr = this->ptr->next;
340 kmp_stats_list::iterator kmp_stats_list::iterator::operator--() {
341 this->ptr = this->ptr->prev;
344 kmp_stats_list::iterator kmp_stats_list::iterator::operator--(
int dummy) {
345 this->ptr = this->ptr->prev;
348 bool kmp_stats_list::iterator::operator!=(
const kmp_stats_list::iterator & rhs) {
349 return this->ptr!=rhs.ptr;
351 bool kmp_stats_list::iterator::operator==(
const kmp_stats_list::iterator & rhs) {
352 return this->ptr==rhs.ptr;
354 kmp_stats_list* kmp_stats_list::iterator::operator*()
const {
361 const char* kmp_stats_output_module::eventsFileName = NULL;
362 const char* kmp_stats_output_module::plotFileName = NULL;
363 int kmp_stats_output_module::printPerThreadFlag = 0;
364 int kmp_stats_output_module::printPerThreadEventsFlag = 0;
367 void kmp_stats_output_module::init()
369 char * statsFileName = getenv(
"KMP_STATS_FILE");
370 eventsFileName = getenv(
"KMP_STATS_EVENTS_FILE");
371 plotFileName = getenv(
"KMP_STATS_PLOT_FILE");
372 char * threadStats = getenv(
"KMP_STATS_THREADS");
373 char * threadEvents = getenv(
"KMP_STATS_EVENTS");
380 std::string baseFileName, pid, suffix;
381 std::stringstream ss;
382 outputFileName = std::string(statsFileName);
383 index = outputFileName.find_last_of(
'.');
384 if(index == std::string::npos) {
385 baseFileName = outputFileName;
387 baseFileName = outputFileName.substr(0, index);
388 suffix = outputFileName.substr(index);
392 outputFileName = baseFileName +
"-" + pid + suffix;
394 eventsFileName = eventsFileName ? eventsFileName :
"events.dat";
395 plotFileName = plotFileName ? plotFileName :
"events.plt";
398 printPerThreadFlag = __kmp_str_match_true(threadStats);
399 printPerThreadEventsFlag = __kmp_str_match_true(threadEvents);
401 if(printPerThreadEventsFlag) {
406 timeStat::clearEventFlags();
412 void kmp_stats_output_module::setupEventColors() {
414 int globalColorIndex = 0;
415 int numGlobalColors =
sizeof(globalColorArray) /
sizeof(rgb_color);
416 for(i=0;i<TIMER_LAST;i++) {
418 timerColorInfo[i] = globalColorArray[globalColorIndex];
419 globalColorIndex = (globalColorIndex+1)%numGlobalColors;
425 void kmp_stats_output_module::printTimerStats(FILE *statsOut, statistic
const * theStats, statistic
const * totalStats)
427 fprintf (statsOut,
"Timer, SampleCount, Min, Mean, Max, Total, SD\n");
428 for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
429 statistic
const * stat = &theStats[s];
432 fprintf (statsOut,
"%-28s, %s\n", timeStat::name(s), stat->format(tag,
true).c_str());
435 for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
438 fprintf(statsOut,
"Total_%-22s, %s\n", timeStat::name(s), totalStats[s].format(tag,
true).c_str());
442 void kmp_stats_output_module::printCounterStats(FILE *statsOut, statistic
const * theStats)
444 fprintf (statsOut,
"Counter, ThreadCount, Min, Mean, Max, Total, SD\n");
445 for (
int s = 0; s<COUNTER_LAST; s++) {
446 statistic
const * stat = &theStats[s];
447 fprintf (statsOut,
"%-25s, %s\n", counter::name(counter_e(s)), stat->format(
' ',
true).c_str());
451 void kmp_stats_output_module::printCounters(FILE * statsOut, counter
const * theCounters)
455 fprintf (statsOut,
"\nCounter, Count\n");
456 for (
int c = 0; c<COUNTER_LAST; c++) {
457 counter
const * stat = &theCounters[c];
458 fprintf (statsOut,
"%-25s, %s\n", counter::name(counter_e(c)), formatSI(stat->getValue(), 9,
' ').c_str());
462 void kmp_stats_output_module::printEvents(FILE* eventsOut, kmp_stats_event_vector* theEvents,
int gtid) {
465 for (
int i = 0; i < theEvents->size(); i++) {
466 kmp_stats_event ev = theEvents->at(i);
467 rgb_color color = getEventColor(ev.getTimerName());
468 fprintf(eventsOut,
"%d %lu %lu %1.1f rgb(%1.1f,%1.1f,%1.1f) %s\n",
472 1.2 - (ev.getNestLevel() * 0.2),
473 color.r, color.g, color.b,
474 timeStat::name(ev.getTimerName())
480 void kmp_stats_output_module::windupExplicitTimers()
485 kmp_stats_list::iterator it;
486 for(it = __kmp_stats_list->begin(); it != __kmp_stats_list->end(); it++) {
487 kmp_stats_list* ptr = *it;
488 ptr->getPartitionedTimers()->windup();
489 for (
int timer=0; timer<EXPLICIT_TIMER_LAST; timer++) {
490 ptr->getExplicitTimer(explicit_timer_e(timer))->stop((timer_e)timer, ptr);
495 void kmp_stats_output_module::printPloticusFile() {
497 int size = __kmp_stats_list->size();
498 FILE* plotOut = fopen(plotFileName,
"w+");
500 fprintf(plotOut,
"#proc page\n" 504 fprintf(plotOut,
"#proc getdata\n" 508 fprintf(plotOut,
"#proc areadef\n" 509 " title: OpenMP Sampling Timeline\n" 510 " titledetails: align=center size=16\n" 511 " rectangle: 1 1 13 9\n" 512 " xautorange: datafield=2,3\n" 513 " yautorange: -1 %d\n\n",
516 fprintf(plotOut,
"#proc xaxis\n" 518 " stubdetails: size=12\n" 519 " label: Time (ticks)\n" 520 " labeldetails: size=14\n\n");
522 fprintf(plotOut,
"#proc yaxis\n" 525 " stubdetails: size=12\n" 527 " labeldetails: size=14\n\n",
530 fprintf(plotOut,
"#proc bars\n" 531 " exactcolorfield: 5\n" 534 " segmentfields: 2 3\n" 535 " barwidthfield: 4\n\n");
538 for(i=0;i<TIMER_LAST;i++) {
540 rgb_color c = getEventColor((timer_e)i);
541 fprintf(plotOut,
"#proc legendentry\n" 542 " sampletype: color\n" 544 " details: rgb(%1.1f,%1.1f,%1.1f)\n\n",
545 timeStat::name((timer_e)i),
551 fprintf(plotOut,
"#proc legend\n" 553 " location: max max\n\n");
564 void kmp_stats_output_module::printHeaderInfo(FILE * statsOut)
566 std::time_t now = std::time(0);
570 std::strftime(&buffer[0],
sizeof(buffer),
"%c", std::localtime(&now));
571 fprintf (statsOut,
"# Time of run: %s\n", &buffer[0]);
572 if (gethostname(&hostName[0],
sizeof(hostName)) == 0)
573 fprintf (statsOut,
"# Hostname: %s\n", &hostName[0]);
574 #if KMP_ARCH_X86 || KMP_ARCH_X86_64 575 fprintf (statsOut,
"# CPU: %s\n", &__kmp_cpuinfo.name[0]);
576 fprintf (statsOut,
"# Family: %d, Model: %d, Stepping: %d\n", __kmp_cpuinfo.family, __kmp_cpuinfo.model, __kmp_cpuinfo.stepping);
577 if (__kmp_cpuinfo.frequency == 0)
578 fprintf (statsOut,
"# Nominal frequency: Unknown\n");
580 fprintf (statsOut,
"# Nominal frequency: %sz\n", formatSI(
double(__kmp_cpuinfo.frequency),9,
'H').c_str());
584 void kmp_stats_output_module::outputStats(
const char* heading)
588 windupExplicitTimers();
590 statistic allStats[TIMER_LAST];
591 statistic totalStats[TIMER_LAST];
592 statistic allCounters[COUNTER_LAST];
594 FILE * statsOut = !outputFileName.empty() ? fopen (outputFileName.c_str(),
"a+") : stderr;
599 if (eventPrintingEnabled()) {
600 eventsOut = fopen(eventsFileName,
"w+");
603 printHeaderInfo (statsOut);
604 fprintf(statsOut,
"%s\n",heading);
606 kmp_stats_list::iterator it;
607 for (it = __kmp_stats_list->begin(); it != __kmp_stats_list->end(); it++) {
608 int t = (*it)->getGtid();
610 if (printPerThreadFlag) {
611 fprintf (statsOut,
"Thread %d\n", t);
612 printTimerStats (statsOut, (*it)->getTimers(), 0);
613 printCounters (statsOut, (*it)->getCounters());
614 fprintf (statsOut,
"\n");
617 if (eventPrintingEnabled()) {
618 kmp_stats_event_vector events = (*it)->getEventVector();
619 printEvents(eventsOut, &events, t);
623 for (timer_e s = timer_e(0); s<TIMER_LAST; s = timer_e(s+1)) {
625 if ((timeStat::masterOnly(s) && (t != 0)) ||
626 (timeStat::workerOnly(s) && (t == 0))
632 statistic * threadStat = (*it)->getTimer(s);
633 allStats[s] += *threadStat;
637 totalStats[s].addSample(threadStat->getTotal());
641 for (counter_e c = counter_e(0); c<COUNTER_LAST; c = counter_e(c+1)) {
642 if (counter::masterOnly(c) && t != 0)
644 allCounters[c].addSample ((*it)->getCounter(c)->getValue());
648 if (eventPrintingEnabled()) {
653 fprintf (statsOut,
"Aggregate for all threads\n");
654 printTimerStats (statsOut, &allStats[0], &totalStats[0]);
655 fprintf (statsOut,
"\n");
656 printCounterStats (statsOut, &allCounters[0]);
658 if (statsOut != stderr)
668 void __kmp_reset_stats()
670 kmp_stats_list::iterator it;
671 for(it = __kmp_stats_list->begin(); it != __kmp_stats_list->end(); it++) {
672 timeStat * timers = (*it)->getTimers();
673 counter * counters = (*it)->getCounters();
674 explicitTimer * eTimers = (*it)->getExplicitTimers();
676 for (
int t = 0; t<TIMER_LAST; t++)
679 for (
int c = 0; c<COUNTER_LAST; c++)
682 for (
int t=0; t<EXPLICIT_TIMER_LAST; t++)
686 (*it)->resetEventVector();
691 void __kmp_output_stats(
const char * heading)
693 __kmp_stats_global_output->outputStats(heading);
697 void __kmp_accumulate_stats_at_exit(
void)
700 if (KMP_XCHG_FIXED32(&statsPrinted, 1) != 0)
703 __kmp_output_stats(
"Statistics on exit");
706 void __kmp_stats_init(
void)
708 __kmp_init_tas_lock( & __kmp_stats_lock );
709 __kmp_stats_start_time = tsc_tick_count::now();
710 __kmp_stats_global_output =
new kmp_stats_output_module();
711 __kmp_stats_list =
new kmp_stats_list();
714 void __kmp_stats_fini(
void)
716 __kmp_accumulate_stats_at_exit();
717 __kmp_stats_list->deallocate();
718 delete __kmp_stats_global_output;
719 delete __kmp_stats_list;
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.