Teuchos Package Browser (Single Doxygen Collection)  Version of the Day
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
Teuchos_StackedTimer.cpp
Go to the documentation of this file.
1 // @HEADER
2 // *****************************************************************************
3 // Teuchos: Common Tools Package
4 //
5 // Copyright 2004 NTESS and the Teuchos contributors.
6 // SPDX-License-Identifier: BSD-3-Clause
7 // *****************************************************************************
8 // @HEADER
9 
10 #include "Teuchos_StackedTimer.hpp"
11 #include <limits>
12 #include <ctime>
13 #include <cctype>
14 #include <algorithm>
15 #include <iterator>
16 #include <fstream>
17 #include <sstream>
18 
19 namespace Teuchos {
20 
21 
23  level_(std::numeric_limits<unsigned>::max()),name_("INVALID"),parent_(nullptr)
24 {}
25 
26 void error_out(const std::string& msg, const bool)
27 {
28  TEUCHOS_TEST_FOR_EXCEPTION(true,std::runtime_error,msg);
29 }
30 
31 
32 void
34  for (unsigned i=0; i<level_; ++i)
35  os << " ";
36  os << name_<<":"<<accumulatedTime()<< " [" << count_started_<<"] ("<< count_updates_ <<")"<<std::endl;
37  double t_total = 0;
38  for (size_t i=0; i<sub_timers_.size(); ++i) {
39  t_total += sub_timers_[i].accumulatedTime();
40  sub_timers_[i].report(os);
41  }
42  if ( sub_timers_.size() == 0 )
43  return;
44  for (unsigned i=0; i<=level_; ++i)
45  os << " ";
46  os << "Remainder: " << accumulatedTime() - t_total<<std::endl;
47 
48 }
49 
50 const BaseTimer*
51 StackedTimer::LevelTimer::findBaseTimer(const std::string &name) const {
52  const BaseTimer* t = nullptr;
53  if (get_full_name() == name) {
54  return this;
55  }
56  else {
57  for (unsigned i=0;i<sub_timers_.size(); ++i){
58  t = sub_timers_[i].findBaseTimer(name);
59  if (t != nullptr)
60  return t;
61  }
62  }
63  return t;
64 }
65 
67 StackedTimer::LevelTimer::findTimer(const std::string &name, bool& found) {
69  auto full_name = get_full_name();
70  if (full_name.size() > name.size())
71  return t;
72  if ( strncmp(full_name.c_str(), name.c_str(), full_name.size()))
73  return t;
74  if (get_full_name() == name) {
75  t = BaseTimer::TimeInfo(this);
76  found = true;
77  }
78  else {
79  for (unsigned i=0;i<sub_timers_.size(); ++i){
80  t = sub_timers_[i].findTimer(name,found);
81  if (found)
82  return t;
83  }
84  }
85  return t;
86 }
87 
88 void
90  int num_timers = timer_.countTimers();
91  flat_names_.resize(num_timers);
92  unsigned pos=0;
94 }
95 
96 void
98  Array<std::string> all_names;
99  mergeCounterNames(*comm, flat_names_, all_names, Union);
100  flat_names_ = all_names;
101 }
102 
103 void
105  // allocate everything
106  int num_names = flat_names_.size();
107  sum_.resize(num_names);
108  count_.resize(num_names);
109  updates_.resize(num_names);
110  active_.resize(num_names);
111 
112  if (options.output_minmax || options.output_histogram || options.output_proc_minmax) {
113  min_.resize(num_names);
114  max_.resize(num_names);
115  if ( options.output_minmax )
116  sum_sq_.resize(num_names);
117  else
118  sum_sq_.resize(0);
119  } else {
120  min_.resize(0);
121  max_.resize(0);
122  sum_sq_.resize(0);
123  }
124 
125  if (options.output_proc_minmax) {
126  procmin_.resize(num_names);
127  procmax_.resize(num_names);
128  }
129 
130 
131  if (options.output_histogram ) {
132  hist_.resize(options.num_histogram);
133  for (int i=0;i<options.num_histogram ; ++i)
134  hist_[i].resize(num_names);
135  }
136 
137  if (options.output_per_proc_stddev) {
138  per_proc_stddev_min_.resize(num_names);
139  per_proc_stddev_max_.resize(num_names);
140  }
141 
142  // Temp data
143  Array<double> time(num_names);
144  Array<unsigned long> count(num_names);
146  if (options.output_total_updates)
147  updates.resize(num_names);
148  Array<int> used(num_names);
149  Array<int> bins;
150  Array<double> per_proc_stddev;
151  if (options.output_per_proc_stddev)
152  per_proc_stddev.resize(num_names);
153 
154  if (options.output_histogram)
155  bins.resize(num_names);
156 
157  // set initial values
158  for (int i=0;i<num_names; ++i) {
159  bool found = false; // ignore result here
160  auto t = timer_.findTimer(flat_names_[i],found);
161  time[i] = t.time;
162  count[i] = t.count;
163  used[i] = t.count==0? 0:1;
164  if (options.output_total_updates)
165  updates[i] = t.updates;
166  if (options.output_per_proc_stddev)
167  per_proc_stddev[i] = t.stdDev;
168  }
169 
170  // Now reduce the data
171  reduce<int, double>(time.getRawPtr(), sum_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
172  reduce(count.getRawPtr(), count_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
173  reduce(used.getRawPtr(), active_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
174 
175  if (min_.size()) {
176  reduceAll(*comm, REDUCE_MAX, num_names, time.getRawPtr(), max_.getRawPtr());
177  for (int i=0;i<num_names;++i)
178  if (!used[i])
179  time[i] = max_[i];
180  reduceAll(*comm, REDUCE_MIN, num_names, time.getRawPtr(), min_.getRawPtr());
181  for (int i=0;i<num_names;++i)
182  if (!used[i])
183  time[i] = 0.;
184  if (procmin_.size()) {
185  Array<int> procmin(num_names);
186  Array<int> procmax(num_names);
187  int commRank = comm->getRank();
188  for (int i=0;i<num_names; ++i) {
189  if (used[i] && (min_[i]==time[i]))
190  procmin[i] = commRank;
191  else
192  procmin[i] = -1;
193  if (used[i] && (max_[i]==time[i]))
194  procmax[i] = commRank;
195  else
196  procmax[i] = -1;
197  }
198  reduceAll(*comm, REDUCE_MAX, num_names, procmin.getRawPtr(), procmin_.getRawPtr());
199  reduceAll(*comm, REDUCE_MAX, num_names, procmax.getRawPtr(), procmax_.getRawPtr());
200  }
201  }
202 
203  if (options.output_histogram) {
204  for (int i=0;i<num_names; ++i) {
205 
206  double dh = (max_[i]-min_[i])/options.num_histogram;
207  if (dh==0) // Put everything into bin 1
208  dh=1;
209  if (used[i]) {
210  int bin=(time[i]- min_[i])/dh;
211  bins[i] = std::max(std::min(bin,options.num_histogram-1) , 0);
212  } else
213  bins[i] = -1;
214  }
215  // Recycle the used array for the temp bin array
216  for (int j=0; j<options.num_histogram; ++j){
217  for (int i=0;i<num_names; ++i) {
218  if (bins[i] == j )
219  used[i]=1;
220  else
221  used[i]=0;
222  }
223  reduce(used.getRawPtr(), hist_[j].getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
224  }
225  }
226 
227  if (sum_sq_.size()) {
228  for (int i=0;i<num_names; ++i)
229  time[i] *= time[i];
230  reduce(time.getRawPtr(), sum_sq_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
231  }
232 
233  if (options.output_per_proc_stddev) {
234  reduceAll(*comm, REDUCE_MIN, num_names, per_proc_stddev.getRawPtr(), per_proc_stddev_min_.getRawPtr());
235  reduceAll(*comm, REDUCE_MAX, num_names, per_proc_stddev.getRawPtr(), per_proc_stddev_max_.getRawPtr());
236  }
237 
238 }
239 
240 std::pair<std::string, std::string> getPrefix(const std::string &name) {
241  for (std::size_t i=name.size()-1; i>0; --i)
242  if (name[i] == '@') {
243  return std::pair<std::string, std::string>(name.substr(0,i), name.substr(i+1));
244  }
245  return std::pair<std::string, std::string>(std::string(""), name);
246 }
247 
248 double
250  int print_level,
251  std::vector<bool> &printed,
252  double parent_time,
253  const OutputOptions &options)
254 {
255  // This replicates printLevel but counts column width instead of
256  // printing to ostream. This must be kept in sync with printLevel()
257  double total_time = 0.0;
258 
259  for (int i=0; i<flat_names_.size(); ++i ) {
260  if (sum_[i]/active_[i] <= options.drop_time)
261  continue;
262  if (printed[i])
263  continue;
264  int level = std::count(flat_names_[i].begin(), flat_names_[i].end(), '@');
265  if ( (level != print_level) || (level >= options.max_levels) )
266  continue;
267  auto split_names = getPrefix(flat_names_[i]);
268  if ( prefix != split_names.first)
269  continue;
270 
271  // Output the indentation level and timer name
272  {
273  std::ostringstream os;
274  for (int l=0; l<level; ++l)
275  os << "| ";
276  // Output the timer name
277  os << split_names.second << ": ";
278  alignments_.timer_names_= std::max(alignments_.timer_names_,os.str().size());
279  }
280 
281  // output averge time
282  {
283  std::ostringstream os;
284  os << sum_[i]/active_[i];
285  alignments_.average_time_ = std::max(alignments_.average_time_,os.str().size());
286  }
287 
288  // output percentage
289  if ( options.output_fraction && parent_time>0) {
290  std::ostringstream os;
291  os << " - "<<sum_[i]/active_[i]/parent_time*100<<"%";
292  alignments_.fraction_ = std::max(alignments_.fraction_,os.str().size());
293  }
294 
295  // output count
296  {
297  std::ostringstream os;
298  os << " ["<<count_[i]/active_[i]<<"]";
299  alignments_.count_ = std::max(alignments_.count_,os.str().size());
300  }
301 
302  // output total counts
303  if ( options.output_total_updates) {
304  std::ostringstream os;
305  os << " ("<<updates_[i]/active_[i]<<")";
306  alignments_.total_updates_ = std::max(alignments_.total_updates_,os.str().size());
307  }
308 
309  // Output min and maxs
310  if ( options.output_minmax && active_[i]>1) {
311  {
312  std::ostringstream os;
313  os << " {min=" << min_[i];
314  alignments_.min_ = std::max(alignments_.min_,os.str().size());
315  }
316  {
317  std::ostringstream os;
318  os << ", max=" << max_[i];
319  if (active_[i] <= 1)
320  os << "}";
321  alignments_.max_ = std::max(alignments_.max_,os.str().size());
322  }
323  if (procmin_.size()) {
324  std::ostringstream os;
325  os << ", proc min=" << procmin_[i];
326  if (active_[i] <= 1)
327  os << "}";
328  alignments_.procmin_ = std::min(alignments_.procmin_,os.str().size());
329  }
330  if (procmax_.size()) {
331  std::ostringstream os;
332  os << ", proc max=" << procmax_[i];
333  if (active_[i] <= 1)
334  os << "}";
335  alignments_.procmax_ = std::max(alignments_.procmax_,os.str().size());
336  }
337  if (active_[i]>1) {
338  std::ostringstream os;
339  os << ", std dev=" << sqrt(std::max<double>(sum_sq_[i]-sum_[i]*sum_[i]/active_[i],0.0)/(active_[i]-1));
340  os << "}";
341  alignments_.stddev_ = std::max(alignments_.stddev_,os.str().size());
342  }
343  }
344  // Output histogram
345  if ( options.output_histogram && active_[i] >1 ) {
346  std::ostringstream os;
347  os << " <";
348  for (int h=0;h<options.num_histogram; ++h) {
349  if (h)
350  os <<", "<<hist_[h][i];
351  else
352  os << hist_[h][i];
353  }
354  os << ">";
355  alignments_.histogram_ = std::max(alignments_.histogram_,os.str().size());
356  }
357 
358  printed[i] = true;
359  double sub_time = computeColumnWidthsForAligment(flat_names_[i], level+1, printed, sum_[i]/active_[i], options);
360 
361  // Print Remainder
362  if (sub_time > 0 ) {
363  if (options.print_names_before_values) {
364  std::ostringstream tmp;
365  for (int l=0; l<=level; ++l)
366  tmp << "| ";
367  tmp << "Remainder: ";
368  alignments_.timer_names_ = std::max(alignments_.timer_names_,tmp.str().size());
369  }
370  {
371  std::ostringstream tmp;
372  tmp << sum_[i]/active_[i]- sub_time;
373  alignments_.average_time_ = std::max(alignments_.average_time_,tmp.str().size());
374  }
375  if ( options.output_fraction && (sum_[i]/active_[i] > 0.) ) {
376  std::ostringstream tmp;
377  tmp << " - "<< (sum_[i]/active_[i]- sub_time)/(sum_[i]/active_[i])*100 << "%";
378  alignments_.fraction_ = std::max(alignments_.fraction_,tmp.str().size());
379  }
380  }
381 
382  total_time += sum_[i]/active_[i];
383  }
384  return total_time;
385 }
386 
387 double
388 StackedTimer::printLevel (std::string prefix, int print_level, std::ostream &os, std::vector<bool> &printed, double parent_time, const OutputOptions &options)
389 {
390  // NOTE: If you change the outputting format or logic in this
391  // function, you must make a corresponding change to the function
392  // computeColumnWidthsForAlignment() or the alignments will be
393  // incorrect if the user requests aligned output!
394 
395  double total_time = 0.0;
396 
397  for (int i=0; i<flat_names_.size(); ++i ) {
398  if (sum_[i]/active_[i] <= options.drop_time) {
399  continue;
400  }
401  if (printed[i])
402  continue;
403  int level = std::count(flat_names_[i].begin(), flat_names_[i].end(), '@');
404  if ( (level != print_level) || (level >= options.max_levels) )
405  continue;
406  auto split_names = getPrefix(flat_names_[i]);
407  if ( prefix != split_names.first)
408  continue;
409 
410  // Output the indentation level
411  if (options.print_names_before_values) {
412  std::ostringstream tmp;
413  for (int l=0; l<level; ++l) {
414  tmp << "| ";
415  }
416  // Output the timer name
417  tmp << split_names.second << ": ";
418  if (options.align_columns)
419  os << std::left << std::setw(alignments_.timer_names_);
420  os << tmp.str();
421  }
422  // output averge time
423  {
424  std::ostringstream tmp;
425  tmp << sum_[i]/active_[i];
426  if (options.align_columns)
427  os << std::left << std::setw(alignments_.average_time_);
428  os << tmp.str();
429  }
430  // output percentage
431  if ( options.output_fraction && parent_time>0) {
432  std::ostringstream tmp;
433  tmp << " - "<<sum_[i]/active_[i]/parent_time*100<<"%";
434  if (options.align_columns)
435  os << std::left << std::setw(alignments_.fraction_);
436  os << tmp.str();
437  }
438  // to keep alignment for later columns if requested
439  else if (options.output_fraction) {
440  if (options.align_columns)
441  os << std::setw(alignments_.fraction_) << " ";
442  }
443  // output count
444  {
445  std::ostringstream tmp;
446  tmp << " ["<<count_[i]/active_[i]<<"]";
447  if (options.align_columns)
448  os << std::left << std::setw(alignments_.count_);
449  os << tmp.str();
450  }
451  // output total counts
452  if ( options.output_total_updates ) {
453  std::ostringstream tmp;
454  tmp << " ("<<updates_[i]/active_[i]<<")";
455  if (options.align_columns)
456  os << std::left << std::setw(alignments_.total_updates_);
457  os << tmp.str();
458  }
459  // Output min and maxs
460  if ( options.output_minmax && active_[i]>1) {
461  {
462  std::ostringstream tmp;
463  tmp << " {min="<<min_[i];
464  if (options.align_columns)
465  os << std::left << std::setw(alignments_.min_);
466  os << tmp.str();
467  }
468  {
469  std::ostringstream tmp;
470  tmp <<", max="<<max_[i];
471  if (active_[i] <= 1)
472  tmp << "}";
473  if (options.align_columns)
474  os << std::left << std::setw(alignments_.max_);
475  os << tmp.str();
476  }
477  if (procmin_.size()) {
478  std::ostringstream tmp;
479  tmp <<", proc min="<<procmin_[i];
480  if (active_[i] <= 1)
481  tmp << "}";
482  if (options.align_columns)
483  os << std::left << std::setw(alignments_.procmin_);
484  os << tmp.str();
485  }
486  if (procmax_.size()) {
487  std::ostringstream tmp;
488  tmp <<", proc max="<<procmax_[i];
489  if (active_[i] <= 1)
490  tmp << "}";
491  if (options.align_columns)
492  os << std::left << std::setw(alignments_.procmax_);
493  os << tmp.str();
494  }
495  if (active_[i]>1) {
496  std::ostringstream tmp;
497  tmp << ", std dev="<<sqrt(std::max<double>(sum_sq_[i]-sum_[i]*sum_[i]/active_[i],0.0)/(active_[i]-1));
498  tmp << "}";
499  if (options.align_columns)
500  os << std::left << std::setw(alignments_.stddev_);
501  os << tmp.str();
502  }
503  }
504  else if ( options.output_minmax) {
505  // this block keeps alignment for single rank timers
506  size_t offset = alignments_.min_ + alignments_.max_ + alignments_.stddev_;
507  for (size_t j=0; j < offset; ++j)
508  os << " ";
509  }
510 
511  // Output histogram
512  if ( options.output_histogram && active_[i] >1 ) {
513  std::ostringstream tmp;
514  tmp << " <";
515  for (int h=0;h<options.num_histogram; ++h) {
516  if (h)
517  tmp <<", "<<hist_[h][i];
518  else
519  tmp << hist_[h][i];
520  }
521  tmp << ">";
522  if (options.align_columns)
523  os << std::left << std::setw(alignments_.histogram_);
524  os << tmp.str();
525  }
526  else if ( options.output_histogram) {
527  // this block keeps alignment for single rank timers
528  for (size_t j=0; j < alignments_.histogram_; ++j)
529  os << " ";
530  }
531 
532  if (options.output_per_proc_stddev) {
533  std::ostringstream tmp;
534  tmp << ", std dev per proc min/max=";
535  tmp << per_proc_stddev_min_[i];
536  tmp << "/";
537  tmp << per_proc_stddev_max_[i];
538  os << tmp.str();
539  }
540 
541  if (! options.print_names_before_values) {
542  std::ostringstream tmp;
543  tmp << " ";
544  for (int l=0; l<level; ++l) {
545  tmp << "| ";
546  }
547  // Output the timer name
548  tmp << split_names.second << ": ";
549  os << tmp.str();
550  }
551 
552  os << std::endl;
553  printed[i] = true;
554  double sub_time = printLevel(flat_names_[i], level+1, os, printed, sum_[i]/active_[i], options);
555 
556  // Print Remainder
557  if (sub_time > 0 ) {
558  if (options.print_names_before_values) {
559  std::ostringstream tmp;
560  for (int l=0; l<=level; ++l)
561  tmp << "| ";
562  tmp << "Remainder: ";
563  if (options.align_columns)
564  os << std::left << std::setw(alignments_.timer_names_);
565  os << tmp.str();
566  }
567  {
568  std::ostringstream tmp;
569  tmp << sum_[i]/active_[i]- sub_time;
570  if (options.align_columns)
571  os << std::left << std::setw(alignments_.average_time_);
572  os << tmp.str();
573  }
574  if ( options.output_fraction && (sum_[i]/active_[i] > 0.) ) {
575  if (options.align_columns)
576  os << std::left << std::setw(alignments_.fraction_);
577  std::ostringstream tmp;
578  tmp << " - "<< (sum_[i]/active_[i]- sub_time)/(sum_[i]/active_[i])*100 << "%";
579  os << tmp.str();
580  }
581  if (! options.print_names_before_values) {
582  {
583  size_t offset = 0;
584  offset += alignments_.count_;
585  if (options.output_total_updates)
586  offset += alignments_.total_updates_;
587  if (options.output_minmax)
589  if (options.output_histogram)
590  offset += alignments_.histogram_;
591  for (size_t j=0; j < offset; ++j)
592  os << " ";
593  }
594  std::ostringstream tmp;
595  tmp << " ";
596  for (int l=0; l<=level; ++l)
597  tmp << "| ";
598  tmp << "Remainder: ";
599  if (options.align_columns)
600  os << std::left << std::setw(alignments_.timer_names_);
601  os << tmp.str();
602  }
603  os << std::endl;
604  }
605  total_time += sum_[i]/active_[i];
606  }
607  return total_time;
608 }
609 
610 static void printXMLEscapedString(std::ostream& os, const std::string& str)
611 {
612  for(char c : str)
613  {
614  switch(c)
615  {
616  case '<':
617  os << "&lt;";
618  break;
619  case '>':
620  os << "&gt;";
621  break;
622  case '\'':
623  os << "&apos;";
624  break;
625  case '"':
626  os << "&quot;";
627  break;
628  case '&':
629  os << "&amp;";
630  break;
631  //NOTE: unescaped curly braces {} are valid in XML,
632  //however Watchr has a bug with parsing them
633  case '{':
634  os << '(';
635  break;
636  case '}':
637  os << ')';
638  break;
639  default:
640  os << c;
641  }
642  }
643 }
644 
645 double
646 StackedTimer::printLevelXML (std::string prefix, int print_level, std::ostream& os, std::vector<bool> &printed, double parent_time, const std::string& rootName)
647 {
648  constexpr int indSpaces = 2;
649  int indent = indSpaces * print_level;
650 
651  double total_time = 0.0;
652 
653  for (int i=0; i<flat_names_.size(); ++i) {
654  if (printed[i])
655  continue;
656  int level = std::count(flat_names_[i].begin(), flat_names_[i].end(), '@');
657  if ( level != print_level)
658  continue;
659  auto split_names = getPrefix(flat_names_[i]);
660  if ( prefix != split_names.first)
661  continue;
662  // Output the indentation level
663  for (int j = 0; j < indent; j++)
664  os << " ";
665  os << "<timing name=\"";
666  if(level == 0 && rootName.length())
667  printXMLEscapedString(os, rootName);
668  else
669  printXMLEscapedString(os, split_names.second);
670  os << "\" value=\"" << sum_[i]/active_[i] << "\"";
671  printed[i] = true;
672  //note: don't need to pass in prependRoot, since the recursive calls don't apply to the root level
673  //Print the children to a temporary string. If it's empty, can close the current XML element on the same line.
674  std::ostringstream osInner;
675  double sub_time = printLevelXML(flat_names_[i], print_level+1, osInner, printed, sum_[i]/active_[i]);
676  std::string innerContents = osInner.str();
677  if(innerContents.length())
678  {
679  os << ">\n";
680  os << innerContents;
681  // Print Remainder
682  if (sub_time > 0 ) {
683  for (int j = 0; j < indent + indSpaces; j++)
684  os << " ";
685  os << "<timing name=\"Remainder\" value=\"" << (sum_[i]/active_[i] - sub_time) << "\"/>\n";
686  }
687  //having printed child nodes, close the XML element on its own line
688  for (int j = 0; j < indent; j++)
689  os << " ";
690  os << "</timing>\n";
691  }
692  else
693  {
694  //Just a leaf node.
695  os << "/>\n";
696  }
697  total_time += sum_[i]/active_[i];
698  }
699  return total_time;
700 }
701 
702 void
703 StackedTimer::report(std::ostream &os, Teuchos::RCP<const Teuchos::Comm<int> > comm, OutputOptions options) {
704  aggregateMpiData(comm, options);
705  if (rank(*comm) == 0 ) {
706  if (options.print_warnings) {
707  os << "*** Teuchos::StackedTimer::report() - Remainder for a level will be ***"
708  << "\n*** incorrect if a timer in the level does not exist on every rank ***"
709  << "\n*** of the MPI Communicator. ***"
710  << std::endl;
711  }
712  if ( (options.max_levels != INT_MAX) && options.print_warnings) {
713  os << "Teuchos::StackedTimer::report() - max_levels manually set to " << options.max_levels
714  << ". \nTo print more levels, increase value of OutputOptions::max_levels." << std::endl;
715  }
716  if ( (! options.print_names_before_values) && (! options.align_columns)) {
717  options.align_columns = true;
718  if (options.print_warnings)
719  os << "Teuchos::StackedTimer::report() - option print_names_before_values=false "
720  << "\nrequires that the option align_columns=true too. Setting the value for "
721  << "\nalign_column to true."
722  << std::endl;
723  }
724  if (options.align_columns) {
725  std::vector<bool> printed(flat_names_.size(), false);
726  computeColumnWidthsForAligment("", 0, printed, 0., options);
727  }
728 
729  std::vector<bool> printed(flat_names_.size(), false);
730  printLevel("", 0, os, printed, 0., options);
731  }
732 }
733 
734 void
735 StackedTimer::reportXML(std::ostream &os, const std::string& datestamp, const std::string& timestamp, Teuchos::RCP<const Teuchos::Comm<int> > comm)
736 {
737  OutputOptions defaultOptions;
738  aggregateMpiData(comm, defaultOptions);
739  if (rank(*comm) == 0 ) {
740  std::vector<bool> printed(flat_names_.size(), false);
741  os << "<?xml version=\"1.0\"?>\n";
742  os << "<performance-report date=\"" << timestamp << "\" name=\"nightly_run_" << datestamp << "\" time-units=\"seconds\">\n";
743  printLevelXML("", 0, os, printed, 0.0);
744  os << "</performance-report>\n";
745  }
746 }
747 
748 std::string
749 StackedTimer::reportWatchrXML(const std::string& name, Teuchos::RCP<const Teuchos::Comm<int> > comm) {
750  const char* rawWatchrDir = getenv("WATCHR_PERF_DIR");
751  const char* rawBuildName = getenv("WATCHR_BUILD_NAME");
752  const char* rawGitSHA = getenv("TRILINOS_GIT_SHA");
753  const char* rawBuildDateOverride = getenv("WATCHR_BUILD_DATE");
754  //WATCHR_PERF_DIR is required (will also check nonempty below)
755  if(!rawWatchrDir)
756  return "";
757  std::string watchrDir = rawWatchrDir;
758  if(!watchrDir.length())
759  {
760  //Output directory has not been set, so don't produce output.
761  return "";
762  }
763  //But the build name is optional (may be empty)
764  std::string buildName = rawBuildName ? rawBuildName : "";
765  std::string datestamp;
766  std::string timestamp;
767  {
768  char buf[256];
769  time_t t;
770  struct tm* tstruct;
771  time(&t);
772  tstruct = gmtime(&t);
773  if(rawBuildDateOverride)
774  {
775  //Parse the year, month, day
776  int year = 0, month = 0, day = 0;
777  sscanf(rawBuildDateOverride, "%d_%d_%d", &year, &month, &day);
778  //Sanity check the values
779  if(year <= 2000 || year > 2100)
780  throw std::invalid_argument("$WATCHR_BUILD_DATE has invalid year or is not in YYYY_MM_DD format.");
781  if(month < 1 || month > 12)
782  throw std::invalid_argument("$WATCHR_BUILD_DATE has invalid month or is not in YYYY_MM_DD format.");
783  if(day < 1 || day > 31)
784  throw std::invalid_argument("$WATCHR_BUILD_DATE has invalid day or is not in YYYY_MM_DD format.");
785  snprintf(buf, 256, "%04d_%02d_%02d", year, month, day);
786  datestamp = buf;
787  strftime(buf, 256, "T%H:%M:%S", tstruct);
788  std::string justTime = buf;
789  snprintf(buf, 256, "%04d-%02d-%02d", year, month, day);
790  timestamp = std::string(buf) + justTime;
791  }
792  else
793  {
794  strftime(buf, 256, "%Y_%m_%d", tstruct);
795  datestamp = buf;
796  strftime(buf, 256, "%FT%H:%M:%S", tstruct);
797  timestamp = buf;
798  }
799  }
800  OutputOptions defaultOptions;
801  aggregateMpiData(comm,defaultOptions);
802  std::string fullFile;
803  //only open the file on rank 0
804  if(rank(*comm) == 0) {
805  std::string nameNoSpaces = name;
806  for(char& c : nameNoSpaces)
807  {
808  if(isspace(c))
809  c = '_';
810  }
811  if(buildName.length())
812  {
813  //In filename, replace all whitespace with underscores
814  std::string buildNameNoSpaces = buildName;
815  for(char& c : buildNameNoSpaces)
816  {
817  if(isspace(c))
818  c = '_';
819  }
820  fullFile = watchrDir + '/' + buildNameNoSpaces + "-" + nameNoSpaces + '_' + datestamp + ".xml";
821  }
822  else
823  fullFile = watchrDir + '/' + nameNoSpaces + '_' + datestamp + ".xml";
824  std::ofstream os(fullFile);
825  std::vector<bool> printed(flat_names_.size(), false);
826  os << "<?xml version=\"1.0\"?>\n";
827  os << "<performance-report date=\"" << timestamp << "\" name=\"nightly_run_" << datestamp << "\" time-units=\"seconds\">\n";
828  if(rawGitSHA)
829  {
830  std::string gitSHA(rawGitSHA);
831  //Output the first 10 (hex) characters
832  if(gitSHA.length() > 10)
833  gitSHA = gitSHA.substr(0, 10);
834  os << " <metadata key=\"Trilinos Version\" value=\"" << gitSHA << "\"/>\n";
835  }
836  printLevelXML("", 0, os, printed, 0.0, buildName + ": " + name);
837  os << "</performance-report>\n";
838  }
839  return fullFile;
840 }
841 
842 void StackedTimer::enableVerbose(const bool enable_verbose)
843 {enable_verbose_ = enable_verbose;}
844 
845 void StackedTimer::enableVerboseTimestamps(const unsigned levels)
846 {verbose_timestamp_levels_ = levels;}
847 
849 {verbose_ostream_ = os;}
850 
852 {enable_timers_ = false;}
853 
855 {enable_timers_ = true;}
856 
858 {
859  flatten();
860  merge(comm);
861  collectRemoteData(comm, options);
863 }
864 
865 double StackedTimer::getMpiAverageTime(const std::string& flat_timer_name)
866 {
867  auto i = getFlatNameIndex(flat_timer_name);
868  return sum_[i] / active_[i];
869 }
870 
871 double StackedTimer::getMpiAverageCount(const std::string& flat_timer_name)
872 {
873  auto i = getFlatNameIndex(flat_timer_name);
874  return static_cast<double>(count_[i]) / static_cast<double>(active_[i]);
875 }
876 
877 int StackedTimer::getFlatNameIndex(const std::string& flat_timer_name)
878 {
880  "ERROR: StackedTimer::getAverageMpiTime() - must call aggregateMpiData() first!");
881 
882  auto search = std::find(flat_names_.begin(),flat_names_.end(),flat_timer_name);
883 
884  TEUCHOS_TEST_FOR_EXCEPTION(search == flat_names_.end(),std::runtime_error,
885  "ERROR: StackedTimer::getAverageMpiTime() - the timer named \""
886  << flat_timer_name << "\" does not exist!");
887 
888  auto i = std::distance(flat_names_.begin(),search);
889  return static_cast<int>(i);
890 }
891 
892 bool StackedTimer::isTimer(const std::string& flat_timer_name)
893 {
895  "ERROR: StackedTimer::isTimer() - must call aggregateMpiData() before using this query!");
896 
897  auto search = std::find(flat_names_.begin(),flat_names_.end(),flat_timer_name);
898  return (search == flat_names_.end()) ? false : true;
899 }
900 
901 } //namespace Teuchos
bool isTimer(const std::string &flat_timer_name)
void setVerboseOstream(const Teuchos::RCP< std::ostream > &os)
Set the ostream for verbose mode(defaults to std::cout).
Array< double > per_proc_stddev_max_
void addTimerNames(Array< std::string > &names, unsigned &pos)
void enableVerboseTimestamps(const unsigned levels)
Enable timestamps in verbose mode for the number of levels specified.
void enableVerbose(const bool enable_verbose)
If set to true, print timer start/stop to verbose ostream.
void merge(Teuchos::RCP< const Teuchos::Comm< int > > comm)
#define TEUCHOS_TEST_FOR_EXCEPTION(throw_exception_test, Exception, msg)
Macro for throwing an exception with breakpointing to ease debugging.
void reduce< int, double >(const double sendBuf[], double recvBuf[], const int count, const EReductionType reductType, const int root, const Comm< int > &comm)
bool enable_verbose_
If set to true, prints to the debug ostream. At construction, default value is set from environment v...
T * getRawPtr()
Return a raw pointer to beginning of array or NULL if unsized.
double printLevelXML(std::string prefix, int level, std::ostream &os, std::vector< bool > &printed, double parent_time, const std::string &rootName="")
Array< double > per_proc_stddev_min_
double getMpiAverageCount(const std::string &flat_timer_name)
bool enable_timers_
Used to disable timers for asynchronous work.
std::string reportWatchrXML(const std::string &name, Teuchos::RCP< const Teuchos::Comm< int > > comm)
unsigned verbose_timestamp_levels_
If set to a value greater than 0, verbose mode will print that many levels of timers with timestamps...
BaseTimer::TimeInfo findTimer(const std::string &name, bool &found)
double printLevel(std::string prefix, int level, std::ostream &os, std::vector< bool > &printed, double parent_time, const OutputOptions &options)
double accumulatedTime(const std::string &name="")
void error_out(const std::string &msg, const bool)
Error reporting function for stacked timer.
The basic timer used internally, uses std::chrono::high_resolution_clock.
static void printXMLEscapedString(std::ostream &os, const std::string &str)
double computeColumnWidthsForAligment(std::string prefix, int print_level, std::vector< bool > &printed, double parent_time, const OutputOptions &options)
void reportXML(std::ostream &os, const std::string &datestamp, const std::string &timestamp, Teuchos::RCP< const Teuchos::Comm< int > > comm)
Array< Array< int > > hist_
void collectRemoteData(Teuchos::RCP< const Teuchos::Comm< int > > comm, const OutputOptions &options)
Array< unsigned long long > updates_
void mergeCounterNames(const Comm< int > &comm, const Array< std::string > &localNames, Array< std::string > &globalNames, const ECounterSetOp setOp)
Merge counter names over all processors.
void resize(size_type new_size, const value_type &x=value_type())
Teuchos::RCP< std::ostream > verbose_ostream_
For debugging, this is the ostream used for printing.
LevelTimer timer_
Base timer.
double getMpiAverageTime(const std::string &flat_timer_name)
Array< std::string > flat_names_
int getFlatNameIndex(const std::string &flat_timer_name)
void report(std::ostream &os)
size_type size() const
LevelTimer()
Default constructor, shouldn&#39;t be used but needed for std::vector.
const BaseTimer * findBaseTimer(const std::string &name) const
void aggregateMpiData(Teuchos::RCP< const Teuchos::Comm< int > > comm, OutputOptions options=OutputOptions())
Smart reference counting pointer class for automatic garbage collection.
Array< unsigned long > count_
iterator begin()
std::pair< std::string, std::string > getPrefix(const std::string &name)
struct Teuchos::StackedTimer::AlignmentWidths alignments_