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