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