Teuchos - Trilinos Tools Package  Version of the Day
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
Teuchos_StackedTimer.hpp
1 // @HEADER BEGIN
2 // @HEADER END
3 
4 #ifndef TEUCHOS_STACKED_TIMER_HPP
5 #define TEUCHOS_STACKED_TIMER_HPP
6 
7 #include "Teuchos_ConfigDefs.hpp"
8 #include "Teuchos_Comm.hpp"
9 #include "Teuchos_DefaultComm.hpp"
10 #include "Teuchos_CommHelpers.hpp"
11 #include "Teuchos_RCP.hpp"
12 #include "Teuchos_Array.hpp"
14 #include <string>
15 #include <vector>
16 #include <cassert>
17 #include <chrono>
18 #include <climits>
19 
20 #if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
21 namespace Kokkos {
22 namespace Profiling {
23 extern void pushRegion (const std::string&);
24 extern void popRegion ();
25 } // namespace Profiling
26 } // namespace Kokkos
27 #endif
28 
29 
30 namespace Teuchos {
31 
33 void error_out(const std::string& msg, const bool fail_all = false);
34 
44 class BaseTimer {
45 
46 public:
47 
48  using Clock = std::chrono::high_resolution_clock;
49 
50  BaseTimer() : accumulation_(0.0), count_started_(0), count_updates_(0), running_(false) {}
51 
53  void start(){
54  if (running_)
55  error_out("Base_Timer:start Failed timer already running");
56  start_time_ = Clock::now();
57 
58  count_started_++;
59  running_ = true;
60  }
61 
63  void stop(){
64  if (!running_)
65  error_out("Base_Timer:stop Failed timer not running");
66  accumulation_ += std::chrono::duration_cast<std::chrono::duration<double>>(Clock::now() - start_time_).count();
67  running_ = false;
68  }
69 
71  unsigned long long incrementUpdates(unsigned long long count=1) {count_updates_ += count; return count_updates_;}
72 
74  double accumulatedTime() const {return accumulation_;}
75 
77  void setAccumulatedTime(double accum=0) {accumulation_=accum;}
78  double accumulatedTimePerUpdate() const {
88  if (count_updates_ > 0) {
89  return accumulation_/count_updates_;
90  } else {
91  return 0;
92  }
93  }
94 
95 
104  if (count_started_> 0) {
105  return accumulation_/count_started_;
106  } else {
107  return 0;
108  }
109  }
110 
117  double difference(const BaseTimer &from) const {
118  return accumulation_ - from.accumulation_;
119  }
120 
122  void reset() {
123  if (running_)
124  error_out("BaseTimer, cannot reset a running timer");
125  accumulation_ = 0.0;
126  count_started_ = count_updates_ = 0;
127  }
128 
130  bool running() const { return running_;}
131 
133  unsigned long numCalls() const { return count_started_; }
134 
136  unsigned long long numUpdates() const { return count_updates_; }
137 
139  void overrideNumCallsForUnitTesting(const unsigned long num_calls)
140  { count_started_ = num_calls; }
141 
143  void overrideNumUpdatesForUnitTesting(const unsigned long long num_updates)
144  { count_updates_ = num_updates; }
145 
146  struct TimeInfo {
147  TimeInfo():time(0.0), count(0), updates(0), running(false){}
148  TimeInfo(BaseTimer* t): time(t->accumulation_), count(t->count_started_), updates(t->count_updates_), running(t->running()) {}
149  double time;
150  unsigned long count;
151  unsigned long long updates;
152  bool running;
153  };
154 
155 protected:
156  double accumulation_; // total time
157  unsigned long count_started_; // Number of times this timer has been started
158  unsigned long long count_updates_; // Total count of items updated during this timer
159  Clock::time_point start_time_;
160  bool running_;
161 
162  friend struct TimeInfo;
163 };
164 
183 {
184 protected:
185 
194  class LevelTimer : public BaseTimer {
195  protected:
196 
197  // TODO: implement operator=
198 
199  unsigned level_;
200  std::string name_;
201  LevelTimer *parent_;
202  std::vector<LevelTimer> sub_timers_;
203  public:
205  LevelTimer();
206 
214  LevelTimer(int level,
215  const char* name = "RootTimer",
216  LevelTimer *parent=nullptr,
217  bool start_timer=true) :
218  BaseTimer(),
219  level_(level),
220  name_(name),
221  parent_(parent)
222  {
223  if ( start_timer )
225 
226  }
227 
229  LevelTimer(const LevelTimer &src) :
230  BaseTimer(src), level_(src.level_), name_(src.name_),parent_(src.parent_), sub_timers_(src.sub_timers_)
231  {
232  for (unsigned i=0;i<sub_timers_.size();++i)
233  sub_timers_[i].parent_ = this;
234  }
235 
241  LevelTimer* start(const char* sub_name) {
242  for (unsigned i=0;i<sub_timers_.size();i++ )
243  if (sub_name == sub_timers_[i].name_ ) {
244  sub_timers_[i].BaseTimer::start();
245  return &sub_timers_[i];
246  }
247  sub_timers_.push_back(LevelTimer(level_+1,sub_name,this,true));
248  return &sub_timers_[sub_timers_.size()-1];
249  }
250 
258  LevelTimer* stop(const std::string &name = "RootTimer") {
259  if (name != name_)
260  error_out("Stopping timer "+name+" But top level running timer is "+name_);
261  BaseTimer::stop();
262  return parent_;
263  }
264 
265 
270  std::string get_full_name() const {
271  std::string parent_name("");
272  if ((parent_ != nullptr))
273  parent_name = parent_->get_full_name() + "@";
274 
275  std::string my_name(name_);
276 
277  std::string full_name = parent_name + my_name;
278  return full_name;
279  }
280 
286  int countTimers() {
287  int count=1;
288  for (unsigned i=0;i<sub_timers_.size(); ++i)
289  count += sub_timers_[i].countTimers();
290  return count;
291  }
292 
293  void addTimerNames(Array<std::string> &names, unsigned &pos) {
294  names[pos++] = get_full_name();
295  for (unsigned i=0;i<sub_timers_.size(); ++i)
296  sub_timers_[i].addTimerNames(names, pos);
297  }
298 
304  double accumulatedTime(const std::string &locate_name="") {
305 
306  if (locate_name == "")
308 
309  std::string first_name,second_name;
310 
311  size_t i = locate_name.find_first_of('@');
312  if ( i >= locate_name.size() ) {
313  first_name = locate_name;
314  second_name = "";
315  } else {
316  first_name.assign(locate_name,0,i);
317  second_name.assign(locate_name,i+1,locate_name.size()-i-1);
318  }
319  for (unsigned j=0;j<sub_timers_.size();++j)
320  if ( first_name == sub_timers_[j].name_)
321  return sub_timers_[j].accumulatedTime(second_name);
322  return 0;
323  }
324 
325  protected:
332  void splitString(const std::string &locate_name, std::string &first_name, std::string &second_name) {
333  size_t i = locate_name.find_first_of('@');
334  if ( i >= locate_name.size() ) {
335  first_name = locate_name;
336  second_name = "";
337  } else {
338  first_name.assign(locate_name,0,i);
339  second_name.assign(locate_name,i+1,locate_name.size()-i-1);
340  }
341  }
342 
343  public:
349  double accumulatedTimePerUpdate(const std::string &locate_name="") {
350 
351  if (locate_name == "")
353 
354  std::string first_name,second_name;
355  splitString(locate_name, first_name, second_name);
356 
357  for (unsigned j=0;j<sub_timers_.size();j++)
358  if ( first_name == sub_timers_[j].name_)
359  return sub_timers_[j].accumulatedTimePerUpdate(second_name);
360  return 0;
361  }
362 
368  double accumulatedTimePerTimerCall(const std::string &locate_name="") {
369 
370  if (locate_name == "")
372 
373  std::string first_name,second_name;
374  splitString(locate_name, first_name, second_name);
375 
376  for (unsigned j=0;j<sub_timers_.size();j++)
377  if ( first_name == sub_timers_[j].name_)
378  return sub_timers_[j].accumulatedTimePerTimerCall(second_name);
379  return 0;
380  }
381 
385  void pack();
386 
392  LevelTimer* unpack(unsigned from);
393 
398  void report(std::ostream &os);
399 
405  const BaseTimer* findBaseTimer(const std::string &name) const;
406 
413  BaseTimer::TimeInfo findTimer(const std::string &name,bool& found);
414 
415  protected:
416 
417 
418  }; // LevelTimer
419 
420 
421 
422 
423 public:
429  explicit StackedTimer(const char *name, const bool start_base_timer = true)
430  : timer_(0,name,nullptr,false)
431  {
432  top_ = &timer_;
433  if (start_base_timer)
434  this->startBaseTimer();
435  }
436 
440  void startBaseTimer() {
441  timer_.BaseTimer::start();
442 #if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
443  ::Kokkos::Profiling::pushRegion(timer_.get_full_name());
444 #endif
445  }
446 
450  void stopBaseTimer() {
451  timer_.BaseTimer::stop();
452 #if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
453  ::Kokkos::Profiling::popRegion();
454 #endif
455  }
456 
462  void start(const std::string name,
463  const bool push_kokkos_profiling_region = true) {
464  if (top_ == nullptr)
465  top_ = timer_.start(name.c_str());
466  else
467  top_ = top_->start(name.c_str());
468 #if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
469  if (push_kokkos_profiling_region) {
470  ::Kokkos::Profiling::pushRegion(name);
471  }
472 #endif
473  }
474 
480  void stop(const std::string &name,
481  const bool pop_kokkos_profiling_region = true) {
482  if (top_)
483  top_ = top_->stop(name);
484  else
485  timer_.BaseTimer::stop();
486 #if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
487  if (pop_kokkos_profiling_region) {
488  ::Kokkos::Profiling::popRegion();
489  }
490 #endif
491  }
492 
497  void incrementUpdates(const long long i = 1) {
499  }
500 
506  double accumulatedTime(const std::string &name="") {
507  if (top_) // Top is null for the head node when nothing is running
508  return top_->accumulatedTime(name);
509  else
510  return timer_.accumulatedTime(name);
511  }
512 
518  double accumulatedTimePerUpdate(const std::string &name="") {
519  if (top_) // Top is null for the head node when nothing is running
520  return top_->accumulatedTimePerUpdate(name);
521  else
522  return timer_.accumulatedTimePerUpdate(name);
523  }
529  double accumulatedTimePerTimerCall(const std::string &name="") {
530  if (top_) // Top is null for the head node when nothing is running
531  return top_->accumulatedTimePerTimerCall(name);
532  else
533  return timer_.accumulatedTimePerTimerCall(name);
534  }
535 
541  const BaseTimer* findBaseTimer(const std::string &name) const {
542  const BaseTimer* baseTimer = timer_.findBaseTimer(name);
543  TEUCHOS_TEST_FOR_EXCEPTION(baseTimer == nullptr, std::runtime_error,
544  "StackedTimer::findBaseTimer() failed to find a timer named \"" << name << "\"!\n");
545  return baseTimer;
546  }
547 
553  BaseTimer::TimeInfo findTimer(const std::string &name) {
554  bool foundTimer = false;
555  const auto timeInfo = timer_.findTimer(name,foundTimer);
556  TEUCHOS_TEST_FOR_EXCEPTION(!foundTimer, std::runtime_error,
557  "StackedTimer::findTimer() failed to find a timer named \"" << name << "\"!\n");
558  return timeInfo;
559  }
560 
561  void report(std::ostream &os) {
562  timer_.report(os);
563  }
564 
566  struct OutputOptions {
567  OutputOptions() : output_fraction(false), output_total_updates(false), output_histogram(false),
568  output_minmax(false), num_histogram(10), max_levels(INT_MAX),
569  print_warnings(true), align_columns(false), print_names_before_values(true) {}
570  bool output_fraction;
571  bool output_total_updates;
572  bool output_histogram;
573  bool output_minmax;
574  int num_histogram;
575  int max_levels;
576  bool print_warnings;
577  bool align_columns;
578  bool print_names_before_values;
579  };
580 
586  void report(std::ostream &os, Teuchos::RCP<const Teuchos::Comm<int> > comm, OutputOptions options = OutputOptions());
587 
588 
589 protected:
594 
595  Array<std::string> flat_names_;
596  Array<double> min_;
597  Array<double> max_;
598  Array<double> sum_;
599  Array<double> sum_sq_;
600  Array<Array<int>> hist_;
601  Array<unsigned long> count_;
602  Array<unsigned long long> updates_;
603  Array<int> active_;
604 
607  std::string::size_type timer_names_;
608  std::string::size_type average_time_;
609  std::string::size_type fraction_;
610  std::string::size_type count_;
611  std::string::size_type total_updates_;
612  std::string::size_type min_;
613  std::string::size_type max_;
614  std::string::size_type stddev_;
615  std::string::size_type histogram_;
616  AlignmentWidths() :
617  timer_names_(0),
618  average_time_(0),
619  fraction_(0),
620  count_(0),
621  total_updates_(0),
622  min_(0),
623  max_(0),
624  stddev_(0),
625  histogram_(0){}
626  } alignments_;
627 
631  void flatten();
632 
637  void merge(Teuchos::RCP<const Teuchos::Comm<int> > comm);
638 
642  void collectRemoteData(Teuchos::RCP<const Teuchos::Comm<int> > comm, const OutputOptions &options );
643 
650  double computeColumnWidthsForAligment(std::string prefix, int print_level,
651  std::vector<bool> &printed, double parent_time,
652  const OutputOptions &options);
653 
657  double printLevel(std::string prefix, int level, std::ostream &os, std::vector<bool> &printed,
658  double parent_time, const OutputOptions &options);
659 
660 }; //StackedTimer
661 
662 
663 } //namespace Teuchos
664 
665 #endif /* TEUCHOS_STACKED_TIMER_HPP */
void setAccumulatedTime(double accum=0)
Setter for accumulated time.
double accumulatedTimePerTimerCall(const std::string &name="")
double difference(const BaseTimer &from) const
Return the difference between two timers in seconds,.
StackedTimer(const char *name, const bool start_base_timer=true)
void overrideNumUpdatesForUnitTesting(const unsigned long long num_updates)
Sets the number of counts for this timer. This is only used for unit testing.
double accumulatedTime() const
Get the total accumulated time since last reset or construction when the timer is running...
void splitString(const std::string &locate_name, std::string &first_name, std::string &second_name)
split a string into two parts split by a &#39;@&#39; if no &#39;@&#39; first gets the full string ...
void stop(const std::string &name, const bool pop_kokkos_profiling_region=true)
LevelTimer(int level, const char *name="RootTimer", LevelTimer *parent=nullptr, bool start_timer=true)
unsigned long long incrementUpdates(unsigned long long count=1)
Increment the total number of items updated between a start stop.
bool running() const
Returns true if the timer is currently accumulating time.
double accumulatedTimePerTimerCall() const
return the average time per timer start/stop
void merge(Teuchos::RCP< const Teuchos::Comm< int > > comm)
#define TEUCHOS_TEST_FOR_EXCEPTION(throw_exception_test, Exception, msg)
Macro for throwing an exception with breakpointing to ease debugging.
double accumulatedTimePerUpdate() const
return the average time per item updated
Teuchos header file which uses auto-configuration information to include necessary C++ headers...
void incrementUpdates(const long long i=1)
void start()
Start a currently stopped timer.
LevelTimer * top_
Current level running.
double accumulatedTimePerUpdate(const std::string &name="")
unsigned long numCalls() const
Returns the number of calls to start().
BaseTimer::TimeInfo findTimer(const std::string &name, bool &found)
double printLevel(std::string prefix, int level, std::ostream &os, std::vector< bool > &printed, double parent_time, const OutputOptions &options)
LevelTimer * unpack(unsigned from)
double accumulatedTime(const std::string &name="")
void start(const std::string name, const bool push_kokkos_profiling_region=true)
double accumulatedTime(const std::string &locate_name="")
void overrideNumCallsForUnitTesting(const unsigned long num_calls)
Sets the number of calls to start() for this timer. This is only used for unit testing.
the basic timer used elsewhere, uses MPI_Wtime for time
double computeColumnWidthsForAligment(std::string prefix, int print_level, std::vector< bool > &printed, double parent_time, const OutputOptions &options)
Stores the column widths for output alignment.
void collectRemoteData(Teuchos::RCP< const Teuchos::Comm< int > > comm, const OutputOptions &options)
LevelTimer(const LevelTimer &src)
Copy constructor.
Timer info at a given level and all the children.
const BaseTimer * findBaseTimer(const std::string &name) const
double accumulatedTimePerUpdate(const std::string &locate_name="")
LevelTimer timer_
Base timer.
double accumulatedTimePerTimerCall(const std::string &locate_name="")
Templated array class derived from the STL std::vector.
void error_out(const std::string &msg, const bool)
Error reporting function for stacked timer.
Abstract interface for distributed-memory communication.
LevelTimer * stop(const std::string &name="RootTimer")
void reset()
Reset all the timer stats, throws if it is already running.
void stop()
Stop a current running timer and accumulate time difference.
LevelTimer()
Default constructor, shouldn&#39;t be used but needed for std::vector.
const BaseTimer * findBaseTimer(const std::string &name) const
Smart reference counting pointer class for automatic garbage collection.
BaseTimer::TimeInfo findTimer(const std::string &name)
This class allows one to push and pop timers on and off a stack.
Provides common capabilities for collecting and reporting performance data across processors...
unsigned long long numUpdates() const
Returns the number of updates added to this timer.
Struct for controlling output options like histograms.
Reference-counted pointer class and non-member templated function implementations.
LevelTimer * start(const char *sub_name)