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