Teuchos - Trilinos Tools Package  Version of the Day
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
Teuchos_StackedTimer.cpp
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 
66 BaseTimer::TimeInfo
67 StackedTimer::LevelTimer::findTimer(const std::string &name, bool& found) {
68  BaseTimer::TimeInfo t;
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;
93  timer_.addTimerNames(flat_names_, pos);
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  // Temp data
138  Array<double> time(num_names);
139  Array<unsigned long> count(num_names);
141  if (options.output_total_updates)
142  updates.resize(num_names);
143  Array<int> used(num_names);
144  Array<int> bins;
145 
146  if (options.output_histogram)
147  bins.resize(num_names);
148 
149  // set initial values
150  for (int i=0;i<num_names; ++i) {
151  bool found = false; // ignore result here
152  auto t = timer_.findTimer(flat_names_[i],found);
153  time[i] = t.time;
154  count[i] = t.count;
155  used[i] = t.count==0? 0:1;
156  if (options.output_total_updates)
157  updates[i] = t.updates;
158  }
159 
160  // Now reduce the data
161  reduce<int, double>(time.getRawPtr(), sum_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
162  reduce(count.getRawPtr(), count_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
163  reduce(used.getRawPtr(), active_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
164 
165  if (min_.size()) {
166  reduceAll(*comm, REDUCE_MAX, num_names, time.getRawPtr(), max_.getRawPtr());
167  for (int i=0;i<num_names;++i)
168  if (!used[i])
169  time[i] = max_[i];
170  reduceAll(*comm, REDUCE_MIN, num_names, time.getRawPtr(), min_.getRawPtr());
171  for (int i=0;i<num_names;++i)
172  if (!used[i])
173  time[i] = 0.;
174  if (procmin_.size()) {
175  Array<int> procmin(num_names);
176  Array<int> procmax(num_names);
177  int commRank = comm->getRank();
178  for (int i=0;i<num_names; ++i) {
179  if (used[i] && (min_[i]==time[i]))
180  procmin[i] = commRank;
181  else
182  procmin[i] = -1;
183  if (used[i] && (max_[i]==time[i]))
184  procmax[i] = commRank;
185  else
186  procmax[i] = -1;
187  }
188  reduceAll(*comm, REDUCE_MAX, num_names, procmin.getRawPtr(), procmin_.getRawPtr());
189  reduceAll(*comm, REDUCE_MAX, num_names, procmax.getRawPtr(), procmax_.getRawPtr());
190  }
191  }
192 
193  if (options.output_histogram) {
194  for (int i=0;i<num_names; ++i) {
195 
196  double dh = (max_[i]-min_[i])/options.num_histogram;
197  if (dh==0) // Put everything into bin 1
198  dh=1;
199  if (used[i]) {
200  int bin=(time[i]- min_[i])/dh;
201  bins[i] = std::max(std::min(bin,options.num_histogram-1) , 0);
202  } else
203  bins[i] = -1;
204  }
205  // Recycle the used array for the temp bin array
206  for (int j=0; j<options.num_histogram; ++j){
207  for (int i=0;i<num_names; ++i) {
208  if (bins[i] == j )
209  used[i]=1;
210  else
211  used[i]=0;
212  }
213  reduce(used.getRawPtr(), hist_[j].getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
214  }
215  }
216 
217  if (sum_sq_.size()) {
218  for (int i=0;i<num_names; ++i)
219  time[i] *= time[i];
220  reduce(time.getRawPtr(), sum_sq_.getRawPtr(), num_names, REDUCE_SUM, 0, *comm);
221  }
222 
223 }
224 
225 std::pair<std::string, std::string> getPrefix(const std::string &name) {
226  for (std::size_t i=name.size()-1; i>0; --i)
227  if (name[i] == '@') {
228  return std::pair<std::string, std::string>(name.substr(0,i), name.substr(i+1));
229  }
230  return std::pair<std::string, std::string>(std::string(""), name);
231 }
232 
233 double
235  int print_level,
236  std::vector<bool> &printed,
237  double parent_time,
238  const OutputOptions &options)
239 {
240  // This replicates printLevel but counts column width instead of
241  // printing to ostream. This must be kept in sync with printLevel()
242  double total_time = 0.0;
243 
244  for (int i=0; i<flat_names_.size(); ++i ) {
245  if (sum_[i]/active_[i] <= options.drop_time)
246  continue;
247  if (printed[i])
248  continue;
249  int level = std::count(flat_names_[i].begin(), flat_names_[i].end(), '@');
250  if ( (level != print_level) || (level >= options.max_levels) )
251  continue;
252  auto split_names = getPrefix(flat_names_[i]);
253  if ( prefix != split_names.first)
254  continue;
255 
256  // Output the indentation level and timer name
257  {
258  std::ostringstream os;
259  for (int l=0; l<level; ++l)
260  os << "| ";
261  // Output the timer name
262  os << split_names.second << ": ";
263  alignments_.timer_names_= std::max(alignments_.timer_names_,os.str().size());
264  }
265 
266  // output averge time
267  {
268  std::ostringstream os;
269  os << sum_[i]/active_[i];
270  alignments_.average_time_ = std::max(alignments_.average_time_,os.str().size());
271  }
272 
273  // output percentage
274  if ( options.output_fraction && parent_time>0) {
275  std::ostringstream os;
276  os << " - "<<sum_[i]/active_[i]/parent_time*100<<"%";
277  alignments_.fraction_ = std::max(alignments_.fraction_,os.str().size());
278  }
279 
280  // output count
281  {
282  std::ostringstream os;
283  os << " ["<<count_[i]/active_[i]<<"]";
284  alignments_.count_ = std::max(alignments_.count_,os.str().size());
285  }
286 
287  // output total counts
288  if ( options.output_total_updates) {
289  std::ostringstream os;
290  os << " ("<<updates_[i]/active_[i]<<")";
291  alignments_.total_updates_ = std::max(alignments_.total_updates_,os.str().size());
292  }
293 
294  // Output min and maxs
295  if ( options.output_minmax && active_[i]>1) {
296  {
297  std::ostringstream os;
298  os << " {min=" << min_[i];
299  alignments_.min_ = std::max(alignments_.min_,os.str().size());
300  }
301  {
302  std::ostringstream os;
303  os << ", max=" << max_[i];
304  if (active_[i] <= 1)
305  os << "}";
306  alignments_.max_ = std::max(alignments_.max_,os.str().size());
307  }
308  if (procmin_.size()) {
309  std::ostringstream os;
310  os << ", proc min=" << procmin_[i];
311  if (active_[i] <= 1)
312  os << "}";
313  alignments_.procmin_ = std::min(alignments_.procmin_,os.str().size());
314  }
315  if (procmax_.size()) {
316  std::ostringstream os;
317  os << ", proc max=" << procmax_[i];
318  if (active_[i] <= 1)
319  os << "}";
320  alignments_.procmax_ = std::max(alignments_.procmax_,os.str().size());
321  }
322  if (active_[i]>1) {
323  std::ostringstream os;
324  os << ", std dev=" << sqrt(std::max<double>(sum_sq_[i]-sum_[i]*sum_[i]/active_[i],0.0)/(active_[i]-1));
325  os << "}";
326  alignments_.stddev_ = std::max(alignments_.stddev_,os.str().size());
327  }
328  }
329  // Output histogram
330  if ( options.output_histogram && active_[i] >1 ) {
331  std::ostringstream os;
332  os << " <";
333  for (int h=0;h<options.num_histogram; ++h) {
334  if (h)
335  os <<", "<<hist_[h][i];
336  else
337  os << hist_[h][i];
338  }
339  os << ">";
340  alignments_.histogram_ = std::max(alignments_.histogram_,os.str().size());
341  }
342 
343  printed[i] = true;
344  double sub_time = computeColumnWidthsForAligment(flat_names_[i], level+1, printed, sum_[i]/active_[i], options);
345 
346  // Print Remainder
347  if (sub_time > 0 ) {
348  if (options.print_names_before_values) {
349  std::ostringstream tmp;
350  for (int l=0; l<=level; ++l)
351  tmp << "| ";
352  tmp << "Remainder: ";
353  alignments_.timer_names_ = std::max(alignments_.timer_names_,tmp.str().size());
354  }
355  {
356  std::ostringstream tmp;
357  tmp << sum_[i]/active_[i]- sub_time;
358  alignments_.average_time_ = std::max(alignments_.average_time_,tmp.str().size());
359  }
360  if ( options.output_fraction && (sum_[i]/active_[i] > 0.) ) {
361  std::ostringstream tmp;
362  tmp << " - "<< (sum_[i]/active_[i]- sub_time)/(sum_[i]/active_[i])*100 << "%";
363  alignments_.fraction_ = std::max(alignments_.fraction_,tmp.str().size());
364  }
365  }
366 
367  total_time += sum_[i]/active_[i];
368  }
369  return total_time;
370 }
371 
372 double
373 StackedTimer::printLevel (std::string prefix, int print_level, std::ostream &os, std::vector<bool> &printed, double parent_time, const OutputOptions &options)
374 {
375  // NOTE: If you change the outputting format or logic in this
376  // function, you must make a corresponding change to the function
377  // computeColumnWidthsForAlignment() or the alignments will be
378  // incorrect if the user requests aligned output!
379 
380  double total_time = 0.0;
381 
382  for (int i=0; i<flat_names_.size(); ++i ) {
383  if (sum_[i]/active_[i] <= options.drop_time) {
384  continue;
385  }
386  if (printed[i])
387  continue;
388  int level = std::count(flat_names_[i].begin(), flat_names_[i].end(), '@');
389  if ( (level != print_level) || (level >= options.max_levels) )
390  continue;
391  auto split_names = getPrefix(flat_names_[i]);
392  if ( prefix != split_names.first)
393  continue;
394 
395  // Output the indentation level
396  if (options.print_names_before_values) {
397  std::ostringstream tmp;
398  for (int l=0; l<level; ++l) {
399  tmp << "| ";
400  }
401  // Output the timer name
402  tmp << split_names.second << ": ";
403  if (options.align_columns)
404  os << std::left << std::setw(alignments_.timer_names_);
405  os << tmp.str();
406  }
407  // output averge time
408  {
409  std::ostringstream tmp;
410  tmp << sum_[i]/active_[i];
411  if (options.align_columns)
412  os << std::left << std::setw(alignments_.average_time_);
413  os << tmp.str();
414  }
415  // output percentage
416  if ( options.output_fraction && parent_time>0) {
417  std::ostringstream tmp;
418  tmp << " - "<<sum_[i]/active_[i]/parent_time*100<<"%";
419  if (options.align_columns)
420  os << std::left << std::setw(alignments_.fraction_);
421  os << tmp.str();
422  }
423  // to keep alignment for later columns if requested
424  else if (options.output_fraction) {
425  if (options.align_columns)
426  os << std::setw(alignments_.fraction_) << " ";
427  }
428  // output count
429  {
430  std::ostringstream tmp;
431  tmp << " ["<<count_[i]/active_[i]<<"]";
432  if (options.align_columns)
433  os << std::left << std::setw(alignments_.count_);
434  os << tmp.str();
435  }
436  // output total counts
437  if ( options.output_total_updates ) {
438  std::ostringstream tmp;
439  tmp << " ("<<updates_[i]/active_[i]<<")";
440  if (options.align_columns)
441  os << std::left << std::setw(alignments_.total_updates_);
442  os << tmp.str();
443  }
444  // Output min and maxs
445  if ( options.output_minmax && active_[i]>1) {
446  {
447  std::ostringstream tmp;
448  tmp << " {min="<<min_[i];
449  if (options.align_columns)
450  os << std::left << std::setw(alignments_.min_);
451  os << tmp.str();
452  }
453  {
454  std::ostringstream tmp;
455  tmp <<", max="<<max_[i];
456  if (active_[i] <= 1)
457  tmp << "}";
458  if (options.align_columns)
459  os << std::left << std::setw(alignments_.max_);
460  os << tmp.str();
461  }
462  if (procmin_.size()) {
463  std::ostringstream tmp;
464  tmp <<", proc min="<<procmin_[i];
465  if (active_[i] <= 1)
466  tmp << "}";
467  if (options.align_columns)
468  os << std::left << std::setw(alignments_.procmin_);
469  os << tmp.str();
470  }
471  if (procmax_.size()) {
472  std::ostringstream tmp;
473  tmp <<", proc max="<<procmax_[i];
474  if (active_[i] <= 1)
475  tmp << "}";
476  if (options.align_columns)
477  os << std::left << std::setw(alignments_.procmax_);
478  os << tmp.str();
479  }
480  if (active_[i]>1) {
481  std::ostringstream tmp;
482  tmp << ", std dev="<<sqrt(std::max<double>(sum_sq_[i]-sum_[i]*sum_[i]/active_[i],0.0)/(active_[i]-1));
483  tmp << "}";
484  if (options.align_columns)
485  os << std::left << std::setw(alignments_.stddev_);
486  os << tmp.str();
487  }
488  }
489  else if ( options.output_minmax) {
490  // this block keeps alignment for single rank timers
491  size_t offset = alignments_.min_ + alignments_.max_ + alignments_.stddev_;
492  for (size_t j=0; j < offset; ++j)
493  os << " ";
494  }
495 
496  // Output histogram
497  if ( options.output_histogram && active_[i] >1 ) {
498  std::ostringstream tmp;
499  tmp << " <";
500  for (int h=0;h<options.num_histogram; ++h) {
501  if (h)
502  tmp <<", "<<hist_[h][i];
503  else
504  tmp << hist_[h][i];
505  }
506  tmp << ">";
507  if (options.align_columns)
508  os << std::left << std::setw(alignments_.histogram_);
509  os << tmp.str();
510  }
511  else if ( options.output_histogram) {
512  // this block keeps alignment for single rank timers
513  for (size_t j=0; j < alignments_.histogram_; ++j)
514  os << " ";
515  }
516 
517  if (! options.print_names_before_values) {
518  std::ostringstream tmp;
519  tmp << " ";
520  for (int l=0; l<level; ++l) {
521  tmp << "| ";
522  }
523  // Output the timer name
524  tmp << split_names.second << ": ";
525  os << tmp.str();
526  }
527 
528  os << std::endl;
529  printed[i] = true;
530  double sub_time = printLevel(flat_names_[i], level+1, os, printed, sum_[i]/active_[i], options);
531 
532  // Print Remainder
533  if (sub_time > 0 ) {
534  if (options.print_names_before_values) {
535  std::ostringstream tmp;
536  for (int l=0; l<=level; ++l)
537  tmp << "| ";
538  tmp << "Remainder: ";
539  if (options.align_columns)
540  os << std::left << std::setw(alignments_.timer_names_);
541  os << tmp.str();
542  }
543  {
544  std::ostringstream tmp;
545  tmp << sum_[i]/active_[i]- sub_time;
546  if (options.align_columns)
547  os << std::left << std::setw(alignments_.average_time_);
548  os << tmp.str();
549  }
550  if ( options.output_fraction && (sum_[i]/active_[i] > 0.) ) {
551  if (options.align_columns)
552  os << std::left << std::setw(alignments_.fraction_);
553  std::ostringstream tmp;
554  tmp << " - "<< (sum_[i]/active_[i]- sub_time)/(sum_[i]/active_[i])*100 << "%";
555  os << tmp.str();
556  }
557  if (! options.print_names_before_values) {
558  {
559  size_t offset = 0;
560  offset += alignments_.count_;
561  if (options.output_total_updates)
562  offset += alignments_.total_updates_;
563  if (options.output_minmax)
564  offset += alignments_.min_ + alignments_.max_ + alignments_.stddev_;
565  if (options.output_histogram)
566  offset += alignments_.histogram_;
567  for (size_t j=0; j < offset; ++j)
568  os << " ";
569  }
570  std::ostringstream tmp;
571  tmp << " ";
572  for (int l=0; l<=level; ++l)
573  tmp << "| ";
574  tmp << "Remainder: ";
575  if (options.align_columns)
576  os << std::left << std::setw(alignments_.timer_names_);
577  os << tmp.str();
578  }
579  os << std::endl;
580  }
581  total_time += sum_[i]/active_[i];
582  }
583  return total_time;
584 }
585 
586 static void printXMLEscapedString(std::ostream& os, const std::string& str)
587 {
588  for(char c : str)
589  {
590  switch(c)
591  {
592  case '<':
593  os << "&lt;";
594  break;
595  case '>':
596  os << "&gt;";
597  break;
598  case '\'':
599  os << "&apos;";
600  break;
601  case '"':
602  os << "&quot;";
603  break;
604  case '&':
605  os << "&amp;";
606  break;
607  //NOTE: unescaped curly braces {} are valid in XML,
608  //however Watchr has a bug with parsing them
609  case '{':
610  os << '(';
611  break;
612  case '}':
613  os << ')';
614  break;
615  default:
616  os << c;
617  }
618  }
619 }
620 
621 double
622 StackedTimer::printLevelXML (std::string prefix, int print_level, std::ostream& os, std::vector<bool> &printed, double parent_time, const std::string& rootName)
623 {
624  constexpr int indSpaces = 2;
625  int indent = indSpaces * print_level;
626 
627  double total_time = 0.0;
628 
629  for (int i=0; i<flat_names_.size(); ++i) {
630  if (printed[i])
631  continue;
632  int level = std::count(flat_names_[i].begin(), flat_names_[i].end(), '@');
633  if ( level != print_level)
634  continue;
635  auto split_names = getPrefix(flat_names_[i]);
636  if ( prefix != split_names.first)
637  continue;
638  // Output the indentation level
639  for (int j = 0; j < indent; j++)
640  os << " ";
641  os << "<timing name=\"";
642  if(level == 0 && rootName.length())
643  printXMLEscapedString(os, rootName);
644  else
645  printXMLEscapedString(os, split_names.second);
646  os << "\" value=\"" << sum_[i]/active_[i] << "\"";
647  printed[i] = true;
648  //note: don't need to pass in prependRoot, since the recursive calls don't apply to the root level
649  //Print the children to a temporary string. If it's empty, can close the current XML element on the same line.
650  std::ostringstream osInner;
651  double sub_time = printLevelXML(flat_names_[i], print_level+1, osInner, printed, sum_[i]/active_[i]);
652  std::string innerContents = osInner.str();
653  if(innerContents.length())
654  {
655  os << ">\n";
656  os << innerContents;
657  // Print Remainder
658  if (sub_time > 0 ) {
659  for (int j = 0; j < indent + indSpaces; j++)
660  os << " ";
661  os << "<timing name=\"Remainder\" value=\"" << (sum_[i]/active_[i] - sub_time) << "\"/>\n";
662  }
663  //having printed child nodes, close the XML element on its own line
664  for (int j = 0; j < indent; j++)
665  os << " ";
666  os << "</timing>\n";
667  }
668  else
669  {
670  //Just a leaf node.
671  os << "/>\n";
672  }
673  total_time += sum_[i]/active_[i];
674  }
675  return total_time;
676 }
677 
678 void
679 StackedTimer::report(std::ostream &os, Teuchos::RCP<const Teuchos::Comm<int> > comm, OutputOptions options) {
680  aggregateMpiData(comm, options);
681  if (rank(*comm) == 0 ) {
682  if (options.print_warnings) {
683  os << "*** Teuchos::StackedTimer::report() - Remainder for a level will be ***"
684  << "\n*** incorrect if a timer in the level does not exist on every rank ***"
685  << "\n*** of the MPI Communicator. ***"
686  << std::endl;
687  }
688  if ( (options.max_levels != INT_MAX) && options.print_warnings) {
689  os << "Teuchos::StackedTimer::report() - max_levels manually set to " << options.max_levels
690  << ". \nTo print more levels, increase value of OutputOptions::max_levels." << std::endl;
691  }
692  if ( (! options.print_names_before_values) && (! options.align_columns)) {
693  options.align_columns = true;
694  if (options.print_warnings)
695  os << "Teuchos::StackedTimer::report() - option print_names_before_values=false "
696  << "\nrequires that the option align_columns=true too. Setting the value for "
697  << "\nalign_column to true."
698  << std::endl;
699  }
700  if (options.align_columns) {
701  std::vector<bool> printed(flat_names_.size(), false);
702  computeColumnWidthsForAligment("", 0, printed, 0., options);
703  }
704 
705  std::vector<bool> printed(flat_names_.size(), false);
706  printLevel("", 0, os, printed, 0., options);
707  }
708 }
709 
710 void
711 StackedTimer::reportXML(std::ostream &os, const std::string& datestamp, const std::string& timestamp, Teuchos::RCP<const Teuchos::Comm<int> > comm)
712 {
713  OutputOptions defaultOptions;
714  aggregateMpiData(comm, defaultOptions);
715  if (rank(*comm) == 0 ) {
716  std::vector<bool> printed(flat_names_.size(), false);
717  os << "<?xml version=\"1.0\"?>\n";
718  os << "<performance-report date=\"" << timestamp << "\" name=\"nightly_run_" << datestamp << "\" time-units=\"seconds\">\n";
719  printLevelXML("", 0, os, printed, 0.0);
720  os << "</performance-report>\n";
721  }
722 }
723 
724 std::string
725 StackedTimer::reportWatchrXML(const std::string& name, Teuchos::RCP<const Teuchos::Comm<int> > comm) {
726  const char* rawWatchrDir = getenv("WATCHR_PERF_DIR");
727  const char* rawBuildName = getenv("WATCHR_BUILD_NAME");
728  const char* rawGitSHA = getenv("TRILINOS_GIT_SHA");
729  const char* rawBuildDateOverride = getenv("WATCHR_BUILD_DATE");
730  //WATCHR_PERF_DIR is required (will also check nonempty below)
731  if(!rawWatchrDir)
732  return "";
733  std::string watchrDir = rawWatchrDir;
734  if(!watchrDir.length())
735  {
736  //Output directory has not been set, so don't produce output.
737  return "";
738  }
739  //But the build name is optional (may be empty)
740  std::string buildName = rawBuildName ? rawBuildName : "";
741  std::string datestamp;
742  std::string timestamp;
743  {
744  char buf[256];
745  time_t t;
746  struct tm* tstruct;
747  time(&t);
748  tstruct = gmtime(&t);
749  if(rawBuildDateOverride)
750  {
751  //Parse the year, month, day
752  int year = 0, month = 0, day = 0;
753  sscanf(rawBuildDateOverride, "%d_%d_%d", &year, &month, &day);
754  //Sanity check the values
755  if(year <= 2000 || year > 2100)
756  throw std::invalid_argument("$WATCHR_BUILD_DATE has invalid year or is not in YYYY_MM_DD format.");
757  if(month < 1 || month > 12)
758  throw std::invalid_argument("$WATCHR_BUILD_DATE has invalid month or is not in YYYY_MM_DD format.");
759  if(day < 1 || day > 31)
760  throw std::invalid_argument("$WATCHR_BUILD_DATE has invalid day or is not in YYYY_MM_DD format.");
761  snprintf(buf, 256, "%04d_%02d_%02d", year, month, day);
762  datestamp = buf;
763  strftime(buf, 256, "T%H:%M:%S", tstruct);
764  std::string justTime = buf;
765  snprintf(buf, 256, "%04d-%02d-%02d", year, month, day);
766  timestamp = std::string(buf) + justTime;
767  }
768  else
769  {
770  strftime(buf, 256, "%Y_%m_%d", tstruct);
771  datestamp = buf;
772  strftime(buf, 256, "%FT%H:%M:%S", tstruct);
773  timestamp = buf;
774  }
775  }
776  OutputOptions defaultOptions;
777  aggregateMpiData(comm,defaultOptions);
778  std::string fullFile;
779  //only open the file on rank 0
780  if(rank(*comm) == 0) {
781  std::string nameNoSpaces = name;
782  for(char& c : nameNoSpaces)
783  {
784  if(isspace(c))
785  c = '_';
786  }
787  if(buildName.length())
788  {
789  //In filename, replace all whitespace with underscores
790  std::string buildNameNoSpaces = buildName;
791  for(char& c : buildNameNoSpaces)
792  {
793  if(isspace(c))
794  c = '_';
795  }
796  fullFile = watchrDir + '/' + buildNameNoSpaces + "-" + nameNoSpaces + '_' + datestamp + ".xml";
797  }
798  else
799  fullFile = watchrDir + '/' + nameNoSpaces + '_' + datestamp + ".xml";
800  std::ofstream os(fullFile);
801  std::vector<bool> printed(flat_names_.size(), false);
802  os << "<?xml version=\"1.0\"?>\n";
803  os << "<performance-report date=\"" << timestamp << "\" name=\"nightly_run_" << datestamp << "\" time-units=\"seconds\">\n";
804  if(rawGitSHA)
805  {
806  std::string gitSHA(rawGitSHA);
807  //Output the first 10 (hex) characters
808  if(gitSHA.length() > 10)
809  gitSHA = gitSHA.substr(0, 10);
810  os << " <metadata key=\"Trilinos Version\" value=\"" << gitSHA << "\"/>\n";
811  }
812  printLevelXML("", 0, os, printed, 0.0, buildName + ": " + name);
813  os << "</performance-report>\n";
814  }
815  return fullFile;
816 }
817 
818 void StackedTimer::enableVerbose(const bool enable_verbose)
819 {enable_verbose_ = enable_verbose;}
820 
821 void StackedTimer::enableVerboseTimestamps(const unsigned levels)
822 {verbose_timestamp_levels_ = levels;}
823 
825 {verbose_ostream_ = os;}
826 
828 {enable_timers_ = false;}
829 
831 {enable_timers_ = true;}
832 
834 {
835  flatten();
836  merge(comm);
837  collectRemoteData(comm, options);
838  global_mpi_aggregation_called_ = true;
839 }
840 
841 double StackedTimer::getMpiAverageTime(const std::string& flat_timer_name)
842 {
843  auto i = getFlatNameIndex(flat_timer_name);
844  return sum_[i] / active_[i];
845 }
846 
847 double StackedTimer::getMpiAverageCount(const std::string& flat_timer_name)
848 {
849  auto i = getFlatNameIndex(flat_timer_name);
850  return static_cast<double>(count_[i]) / static_cast<double>(active_[i]);
851 }
852 
853 int StackedTimer::getFlatNameIndex(const std::string& flat_timer_name)
854 {
855  TEUCHOS_TEST_FOR_EXCEPTION(!global_mpi_aggregation_called_, std::runtime_error,
856  "ERROR: StackedTimer::getAverageMpiTime() - must call aggregateMpiData() first!");
857 
858  auto search = std::find(flat_names_.begin(),flat_names_.end(),flat_timer_name);
859 
860  TEUCHOS_TEST_FOR_EXCEPTION(search == flat_names_.end(),std::runtime_error,
861  "ERROR: StackedTimer::getAverageMpiTime() - the timer named \""
862  << flat_timer_name << "\" does not exist!");
863 
864  auto i = std::distance(flat_names_.begin(),search);
865  return static_cast<int>(i);
866 }
867 
868 bool StackedTimer::isTimer(const std::string& flat_timer_name)
869 {
870  TEUCHOS_TEST_FOR_EXCEPTION(!global_mpi_aggregation_called_,std::runtime_error,
871  "ERROR: StackedTimer::isTimer() - must call aggregateMpiData() before using this query!");
872 
873  auto search = std::find(flat_names_.begin(),flat_names_.end(),flat_timer_name);
874  return (search == flat_names_.end()) ? false : true;
875 }
876 
877 } //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).
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.
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="")
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.
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)
void collectRemoteData(Teuchos::RCP< const Teuchos::Comm< int > > comm, const OutputOptions &options)
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)
int getFlatNameIndex(const std::string &flat_timer_name)
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.
iterator begin()