40#include "Teuchos_StackedTimer.hpp"
52 level_(std::numeric_limits<unsigned>::max()),name_(
"INVALID"),parent_(nullptr)
63 for (
unsigned i=0; i<level_; ++i)
65 os << name_<<
":"<<
accumulatedTime()<<
" [" << count_started_<<
"] ("<< count_updates_ <<
")"<<std::endl;
67 for (
size_t i=0; i<sub_timers_.size(); ++i) {
68 t_total += sub_timers_[i].accumulatedTime();
69 sub_timers_[i].report(os);
71 if ( sub_timers_.size() == 0 )
73 for (
unsigned i=0; i<=level_; ++i)
82 if (get_full_name() == name) {
86 for (
unsigned i=0;i<sub_timers_.size(); ++i){
87 t = sub_timers_[i].findBaseTimer(name);
97 BaseTimer::TimeInfo t;
98 auto full_name = get_full_name();
99 if (full_name.size() > name.size())
101 if ( strncmp(full_name.c_str(), name.c_str(), full_name.size()))
103 if (get_full_name() == name) {
104 t = BaseTimer::TimeInfo(
this);
108 for (
unsigned i=0;i<sub_timers_.size(); ++i){
109 t = sub_timers_[i].findTimer(name,found);
120 flat_names_.
resize(num_timers);
122 timer_.addTimerNames(flat_names_, pos);
129 flat_names_ = all_names;
135 int num_names = flat_names_.
size();
138 updates_.
resize(num_names);
139 active_.
resize(num_names);
141 if (options.output_minmax || options.output_histogram || options.output_proc_minmax) {
144 if ( options.output_minmax )
145 sum_sq_.
resize(num_names);
154 if (options.output_proc_minmax) {
155 procmin_.
resize(num_names);
156 procmax_.
resize(num_names);
160 if (options.output_histogram ) {
161 hist_.resize(options.num_histogram);
162 for (
int i=0;i<options.num_histogram ; ++i)
163 hist_[i].resize(num_names);
170 if (options.output_total_updates)
171 updates.
resize(num_names);
175 if (options.output_histogram)
179 for (
int i=0;i<num_names; ++i) {
184 used[i] = t.count==0? 0:1;
185 if (options.output_total_updates)
186 updates[i] = t.updates;
196 for (
int i=0;i<num_names;++i)
200 for (
int i=0;i<num_names;++i)
203 if (procmin_.
size()) {
206 int commRank = comm->getRank();
207 for (
int i=0;i<num_names; ++i) {
208 if (used[i] && (min_[i]==time[i]))
209 procmin[i] = commRank;
212 if (used[i] && (max_[i]==time[i]))
213 procmax[i] = commRank;
222 if (options.output_histogram) {
223 for (
int i=0;i<num_names; ++i) {
225 double dh = (max_[i]-min_[i])/options.num_histogram;
229 int bin=(time[i]- min_[i])/dh;
230 bins[i] = std::max(std::min(bin,options.num_histogram-1) , 0);
235 for (
int j=0; j<options.num_histogram; ++j){
236 for (
int i=0;i<num_names; ++i) {
246 if (sum_sq_.
size()) {
247 for (
int i=0;i<num_names; ++i)
254std::pair<std::string, std::string> getPrefix(
const std::string &name) {
255 for (std::size_t i=name.size()-1; i>0; --i)
256 if (name[i] ==
'@') {
257 return std::pair<std::string, std::string>(name.substr(0,i), name.substr(i+1));
259 return std::pair<std::string, std::string>(std::string(
""), name);
265 std::vector<bool> &printed,
271 double total_time = 0.0;
273 for (
int i=0; i<flat_names_.
size(); ++i ) {
274 if (sum_[i]/active_[i] <= options.drop_time)
278 int level = std::count(flat_names_[i].begin(), flat_names_[i].end(),
'@');
279 if ( (level != print_level) || (level >= options.max_levels) )
281 auto split_names = getPrefix(flat_names_[i]);
282 if ( prefix != split_names.first)
287 std::ostringstream os;
288 for (
int l=0; l<level; ++l)
291 os << split_names.second <<
": ";
292 alignments_.timer_names_= std::max(alignments_.timer_names_,os.str().size());
297 std::ostringstream os;
298 os << sum_[i]/active_[i];
299 alignments_.average_time_ = std::max(alignments_.average_time_,os.str().size());
303 if ( options.output_fraction && parent_time>0) {
304 std::ostringstream os;
305 os <<
" - "<<sum_[i]/active_[i]/parent_time*100<<
"%";
306 alignments_.fraction_ = std::max(alignments_.fraction_,os.str().size());
311 std::ostringstream os;
312 os <<
" ["<<count_[i]/active_[i]<<
"]";
313 alignments_.count_ = std::max(alignments_.count_,os.str().size());
317 if ( options.output_total_updates) {
318 std::ostringstream os;
319 os <<
" ("<<updates_[i]/active_[i]<<
")";
320 alignments_.total_updates_ = std::max(alignments_.total_updates_,os.str().size());
324 if ( options.output_minmax && active_[i]>1) {
326 std::ostringstream os;
327 os <<
" {min=" << min_[i];
328 alignments_.min_ = std::max(alignments_.min_,os.str().size());
331 std::ostringstream os;
332 os <<
", max=" << max_[i];
335 alignments_.max_ = std::max(alignments_.max_,os.str().size());
337 if (procmin_.
size()) {
338 std::ostringstream os;
339 os <<
", proc min=" << procmin_[i];
342 alignments_.procmin_ = std::min(alignments_.procmin_,os.str().size());
344 if (procmax_.
size()) {
345 std::ostringstream os;
346 os <<
", proc max=" << procmax_[i];
349 alignments_.procmax_ = std::max(alignments_.procmax_,os.str().size());
352 std::ostringstream os;
353 os <<
", std dev=" << sqrt(std::max<double>(sum_sq_[i]-sum_[i]*sum_[i]/active_[i],0.0)/(active_[i]-1));
355 alignments_.stddev_ = std::max(alignments_.stddev_,os.str().size());
359 if ( options.output_histogram && active_[i] >1 ) {
360 std::ostringstream os;
362 for (
int h=0;h<options.num_histogram; ++h) {
364 os <<
", "<<hist_[h][i];
369 alignments_.histogram_ = std::max(alignments_.histogram_,os.str().size());
377 if (options.print_names_before_values) {
378 std::ostringstream tmp;
379 for (
int l=0; l<=level; ++l)
381 tmp <<
"Remainder: ";
382 alignments_.timer_names_ = std::max(alignments_.timer_names_,tmp.str().size());
385 std::ostringstream tmp;
386 tmp << sum_[i]/active_[i]- sub_time;
387 alignments_.average_time_ = std::max(alignments_.average_time_,tmp.str().size());
389 if ( options.output_fraction && (sum_[i]/active_[i] > 0.) ) {
390 std::ostringstream tmp;
391 tmp <<
" - "<< (sum_[i]/active_[i]- sub_time)/(sum_[i]/active_[i])*100 <<
"%";
392 alignments_.fraction_ = std::max(alignments_.fraction_,tmp.str().size());
396 total_time += sum_[i]/active_[i];
409 double total_time = 0.0;
411 for (
int i=0; i<flat_names_.
size(); ++i ) {
412 if (sum_[i]/active_[i] <= options.drop_time) {
417 int level = std::count(flat_names_[i].begin(), flat_names_[i].end(),
'@');
418 if ( (level != print_level) || (level >= options.max_levels) )
420 auto split_names = getPrefix(flat_names_[i]);
421 if ( prefix != split_names.first)
425 if (options.print_names_before_values) {
426 std::ostringstream tmp;
427 for (
int l=0; l<level; ++l) {
431 tmp << split_names.second <<
": ";
432 if (options.align_columns)
433 os << std::left << std::setw(alignments_.timer_names_);
438 std::ostringstream tmp;
439 tmp << sum_[i]/active_[i];
440 if (options.align_columns)
441 os << std::left << std::setw(alignments_.average_time_);
445 if ( options.output_fraction && parent_time>0) {
446 std::ostringstream tmp;
447 tmp <<
" - "<<sum_[i]/active_[i]/parent_time*100<<
"%";
448 if (options.align_columns)
449 os << std::left << std::setw(alignments_.fraction_);
453 else if (options.output_fraction) {
454 if (options.align_columns)
455 os << std::setw(alignments_.fraction_) <<
" ";
459 std::ostringstream tmp;
460 tmp <<
" ["<<count_[i]/active_[i]<<
"]";
461 if (options.align_columns)
462 os << std::left << std::setw(alignments_.count_);
466 if ( options.output_total_updates ) {
467 std::ostringstream tmp;
468 tmp <<
" ("<<updates_[i]/active_[i]<<
")";
469 if (options.align_columns)
470 os << std::left << std::setw(alignments_.total_updates_);
474 if ( options.output_minmax && active_[i]>1) {
476 std::ostringstream tmp;
477 tmp <<
" {min="<<min_[i];
478 if (options.align_columns)
479 os << std::left << std::setw(alignments_.min_);
483 std::ostringstream tmp;
484 tmp <<
", max="<<max_[i];
487 if (options.align_columns)
488 os << std::left << std::setw(alignments_.max_);
491 if (procmin_.
size()) {
492 std::ostringstream tmp;
493 tmp <<
", proc min="<<procmin_[i];
496 if (options.align_columns)
497 os << std::left << std::setw(alignments_.procmin_);
500 if (procmax_.
size()) {
501 std::ostringstream tmp;
502 tmp <<
", proc max="<<procmax_[i];
505 if (options.align_columns)
506 os << std::left << std::setw(alignments_.procmax_);
510 std::ostringstream tmp;
511 tmp <<
", std dev="<<sqrt(std::max<double>(sum_sq_[i]-sum_[i]*sum_[i]/active_[i],0.0)/(active_[i]-1));
513 if (options.align_columns)
514 os << std::left << std::setw(alignments_.stddev_);
518 else if ( options.output_minmax) {
520 size_t offset = alignments_.min_ + alignments_.max_ + alignments_.stddev_;
521 for (
size_t j=0; j < offset; ++j)
526 if ( options.output_histogram && active_[i] >1 ) {
527 std::ostringstream tmp;
529 for (
int h=0;h<options.num_histogram; ++h) {
531 tmp <<
", "<<hist_[h][i];
536 if (options.align_columns)
537 os << std::left << std::setw(alignments_.histogram_);
540 else if ( options.output_histogram) {
542 for (
size_t j=0; j < alignments_.histogram_; ++j)
546 if (! options.print_names_before_values) {
547 std::ostringstream tmp;
549 for (
int l=0; l<level; ++l) {
553 tmp << split_names.second <<
": ";
559 double sub_time =
printLevel(flat_names_[i], level+1, os, printed, sum_[i]/active_[i], options);
563 if (options.print_names_before_values) {
564 std::ostringstream tmp;
565 for (
int l=0; l<=level; ++l)
567 tmp <<
"Remainder: ";
568 if (options.align_columns)
569 os << std::left << std::setw(alignments_.timer_names_);
573 std::ostringstream tmp;
574 tmp << sum_[i]/active_[i]- sub_time;
575 if (options.align_columns)
576 os << std::left << std::setw(alignments_.average_time_);
579 if ( options.output_fraction && (sum_[i]/active_[i] > 0.) ) {
580 if (options.align_columns)
581 os << std::left << std::setw(alignments_.fraction_);
582 std::ostringstream tmp;
583 tmp <<
" - "<< (sum_[i]/active_[i]- sub_time)/(sum_[i]/active_[i])*100 <<
"%";
586 if (! options.print_names_before_values) {
589 offset += alignments_.count_;
590 if (options.output_total_updates)
591 offset += alignments_.total_updates_;
592 if (options.output_minmax)
593 offset += alignments_.min_ + alignments_.max_ + alignments_.stddev_;
594 if (options.output_histogram)
595 offset += alignments_.histogram_;
596 for (
size_t j=0; j < offset; ++j)
599 std::ostringstream tmp;
601 for (
int l=0; l<=level; ++l)
603 tmp <<
"Remainder: ";
604 if (options.align_columns)
605 os << std::left << std::setw(alignments_.timer_names_);
610 total_time += sum_[i]/active_[i];
615static void printXMLEscapedString(std::ostream& os,
const std::string& str)
651StackedTimer::printLevelXML (std::string prefix,
int print_level, std::ostream& os, std::vector<bool> &printed,
double parent_time,
const std::string& rootName)
653 constexpr int indSpaces = 2;
654 int indent = indSpaces * print_level;
656 double total_time = 0.0;
658 for (
int i=0; i<flat_names_.
size(); ++i) {
661 int level = std::count(flat_names_[i].begin(), flat_names_[i].end(),
'@');
662 if ( level != print_level)
664 auto split_names = getPrefix(flat_names_[i]);
665 if ( prefix != split_names.first)
668 for (
int j = 0; j < indent; j++)
670 os <<
"<timing name=\"";
671 if(level == 0 && rootName.length())
672 printXMLEscapedString(os, rootName);
674 printXMLEscapedString(os, split_names.second);
675 os <<
"\" value=\"" << sum_[i]/active_[i] <<
"\"";
679 std::ostringstream osInner;
680 double sub_time =
printLevelXML(flat_names_[i], print_level+1, osInner, printed, sum_[i]/active_[i]);
681 std::string innerContents = osInner.str();
682 if(innerContents.length())
688 for (
int j = 0; j < indent + indSpaces; j++)
690 os <<
"<timing name=\"Remainder\" value=\"" << (sum_[i]/active_[i] - sub_time) <<
"\"/>\n";
693 for (
int j = 0; j < indent; j++)
702 total_time += sum_[i]/active_[i];
712 if (rank(*comm) == 0 ) {
713 if (options.print_warnings) {
714 os <<
"*** Teuchos::StackedTimer::report() - Remainder for a level will be ***"
715 <<
"\n*** incorrect if a timer in the level does not exist on every rank ***"
716 <<
"\n*** of the MPI Communicator. ***"
719 if ( (options.max_levels != INT_MAX) && options.print_warnings) {
720 os <<
"Teuchos::StackedTimer::report() - max_levels manually set to " << options.max_levels
721 <<
". \nTo print more levels, increase value of OutputOptions::max_levels." << std::endl;
723 if ( (! options.print_names_before_values) && (! options.align_columns)) {
724 options.align_columns =
true;
725 if (options.print_warnings)
726 os <<
"Teuchos::StackedTimer::report() - option print_names_before_values=false "
727 <<
"\nrequires that the option align_columns=true too. Setting the value for "
728 <<
"\nalign_column to true."
731 if (options.align_columns) {
732 std::vector<bool> printed(flat_names_.
size(),
false);
736 std::vector<bool> printed(flat_names_.
size(),
false);
748 if (rank(*comm) == 0 ) {
749 std::vector<bool> printed(flat_names_.
size(),
false);
750 os <<
"<?xml version=\"1.0\"?>\n";
751 os <<
"<performance-report date=\"" << timestamp <<
"\" name=\"nightly_run_" << datestamp <<
"\" time-units=\"seconds\">\n";
753 os <<
"</performance-report>\n";
759 const char* rawWatchrDir = getenv(
"WATCHR_PERF_DIR");
760 const char* rawBuildName = getenv(
"WATCHR_BUILD_NAME");
761 const char* rawGitSHA = getenv(
"TRILINOS_GIT_SHA");
762 const char* rawBuildDateOverride = getenv(
"WATCHR_BUILD_DATE");
766 std::string watchrDir = rawWatchrDir;
767 if(!watchrDir.length())
773 std::string buildName = rawBuildName ? rawBuildName :
"";
774 std::string datestamp;
775 std::string timestamp;
781 tstruct = gmtime(&t);
782 if(rawBuildDateOverride)
785 int year = 0, month = 0, day = 0;
786 sscanf(rawBuildDateOverride,
"%d_%d_%d", &year, &month, &day);
788 if(year <= 2000 || year > 2100)
789 throw std::invalid_argument(
"$WATCHR_BUILD_DATE has invalid year or is not in YYYY_MM_DD format.");
790 if(month < 1 || month > 12)
791 throw std::invalid_argument(
"$WATCHR_BUILD_DATE has invalid month or is not in YYYY_MM_DD format.");
792 if(day < 1 || day > 31)
793 throw std::invalid_argument(
"$WATCHR_BUILD_DATE has invalid day or is not in YYYY_MM_DD format.");
794 snprintf(buf, 256,
"%04d_%02d_%02d", year, month, day);
796 strftime(buf, 256,
"T%H:%M:%S", tstruct);
797 std::string justTime = buf;
798 snprintf(buf, 256,
"%04d-%02d-%02d", year, month, day);
799 timestamp = std::string(buf) + justTime;
803 strftime(buf, 256,
"%Y_%m_%d", tstruct);
805 strftime(buf, 256,
"%FT%H:%M:%S", tstruct);
813 std::string fullFile;
815 if(rank(*comm) == 0) {
816 std::string nameNoSpaces = name;
817 for(
char& c : nameNoSpaces)
822 if(buildName.length())
825 std::string buildNameNoSpaces = buildName;
826 for(
char& c : buildNameNoSpaces)
831 fullFile = watchrDir +
'/' + buildNameNoSpaces +
"-" + nameNoSpaces +
'_' + datestamp +
".xml";
834 fullFile = watchrDir +
'/' + nameNoSpaces +
'_' + datestamp +
".xml";
835 std::ofstream os(fullFile);
836 std::vector<bool> printed(flat_names_.
size(),
false);
837 os <<
"<?xml version=\"1.0\"?>\n";
838 os <<
"<performance-report date=\"" << timestamp <<
"\" name=\"nightly_run_" << datestamp <<
"\" time-units=\"seconds\">\n";
841 std::string gitSHA(rawGitSHA);
843 if(gitSHA.length() > 10)
844 gitSHA = gitSHA.substr(0, 10);
845 os <<
" <metadata key=\"Trilinos Version\" value=\"" << gitSHA <<
"\"/>\n";
847 printLevelXML(
"", 0, os, printed, 0.0, buildName +
": " + name);
848 os <<
"</performance-report>\n";
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.
void resize(size_type new_size, const value_type &x=value_type())
the basic timer used elsewhere, uses MPI_Wtime for time
Abstract interface for distributed-memory communication.
Smart reference counting pointer class for automatic garbage collection.
void report(std::ostream &os)
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 ×tamp, 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.