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