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