Teuchos_StackedTimer.hpp

Go to the documentation of this file.

// @HEADER BEGIN
// @HEADER END

#ifndef TEUCHOS_STACKED_TIMER_HPP
#define TEUCHOS_STACKED_TIMER_HPP

#include "Teuchos_ConfigDefs.hpp"
#include "Teuchos_Comm.hpp"
#include "Teuchos_DefaultComm.hpp"
#include "Teuchos_CommHelpers.hpp"
#include "Teuchos_RCP.hpp"
#include "Teuchos_Array.hpp"
#include "Teuchos_PerformanceMonitorBase.hpp"
#include <string>
#include <vector>
#include <cassert>
#include <chrono>
#include <climits>

#if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
namespace Kokkos {
namespace Profiling {
extern void pushRegion (const std::string&);
extern void popRegion ();
} // namespace Profiling
} // namespace Kokkos
#endif


namespace Teuchos {
  
void error_out(const std::string& msg, const bool fail_all = false);

class BaseTimer {

public:

  using Clock = std::chrono::high_resolution_clock;
  
  BaseTimer() : accumulation_(0.0), count_started_(0), count_updates_(0), running_(false) {}

  void start(){
    if (running_)
      error_out("Base_Timer:start Failed timer already running");
    start_time_ = Clock::now(); 

    count_started_++;
    running_ = true;
  }

  void stop(){
    if (!running_)
      error_out("Base_Timer:stop Failed timer not running");
    accumulation_ += std::chrono::duration_cast<std::chrono::duration<double>>(Clock::now() - start_time_).count();
    running_ = false;
  }

  unsigned long incrementCount(unsigned long count=1) {count_updates_ += count; return count_updates_;}

  double accumulatedTime() const {return accumulation_;}

  void setAccumulatedTime(double accum=0)  {accumulation_=accum;}
  double accumulatedTimePerUpdate()const {
    if (count_updates_ > 0) {
      return accumulation_/count_updates_;
    } else {
      return 0;
    }
  }


  double accumulatedTimePerTimerCall()const {
    if (count_started_> 0) {
      return accumulation_/count_started_;
    } else {
      return 0;
    }
  }

  double difference(const BaseTimer &from) const {
    return accumulation_ - from.accumulation_;
  }

  void reset() {
    if (running_)
       error_out("BaseTimer, cannot reset a running timer");
    accumulation_=0.0;
    count_started_ = count_updates_ = 0;
  }

  unsigned long totalUpdates()const {return count_updates_;}

  bool running() const { return running_;}

  struct TimeInfo {
    TimeInfo():time(0.0), count(0), updates(0), running(false){}
    TimeInfo(BaseTimer* t): time(t->accumulation_), count(t->count_started_), updates(t->count_updates_), running(t->running()) {}
    double time;
    unsigned long count;
    unsigned long long updates;
    bool running;
  };

protected:
  double accumulation_;       // total time
  unsigned long count_started_; // Number of times this timer has been started
  unsigned long long count_updates_; // Total count of items updated during this timer
  Clock::time_point start_time_;
  bool running_;

  friend struct TimeInfo;
};

class StackedTimer
{
protected:

  class LevelTimer : public BaseTimer {
  protected:

    // TODO: implement operator=

    unsigned level_;
    std::string name_;
    LevelTimer *parent_;
    std::vector<LevelTimer> sub_timers_;
  public:
    LevelTimer();

    LevelTimer(int level,
        const char* name = "RootTimer",
        LevelTimer *parent=NULL,
        bool start_timer=true) :
          BaseTimer(),
          level_(level),
          name_(name),
          parent_(parent)
    {
      if ( start_timer )
        BaseTimer::start();

    }

    LevelTimer(const LevelTimer &src) :
      BaseTimer(src), level_(src.level_), name_(src.name_),parent_(src.parent_), sub_timers_(src.sub_timers_)
    {
      for (unsigned i=0;i<sub_timers_.size();++i) 
        sub_timers_[i].parent_ = this;
    }

    LevelTimer* start(const char* sub_name) {
      for (unsigned i=0;i<sub_timers_.size();i++ )
        if (sub_name == sub_timers_[i].name_ ) {
          sub_timers_[i].BaseTimer::start();
          return &sub_timers_[i];
        }
      sub_timers_.push_back(LevelTimer(level_+1,sub_name,this,true));
      return &sub_timers_[sub_timers_.size()-1];
    }

    LevelTimer* stop(const std::string &name = "RootTimer") {
      if (name != name_)
        error_out("Stopping timer "+name+" But top level running timer is "+name_);
      BaseTimer::stop();
      return parent_;
    }


    std::string get_full_name() {
      std::string parent_name("");
      if ((parent_ != NULL) && (parent_->level_ > 0))
        parent_name = parent_->get_full_name() + "@";

      std::string my_name(name_);

      std::string full_name = parent_name + my_name;
      return full_name;
    }

    int countTimers() {
      int count=1;
      for (unsigned i=0;i<sub_timers_.size(); ++i)
        count += sub_timers_[i].countTimers();
      return count;
    }
    
    void addTimerNames(Array<std::string> &names, unsigned &pos) {
      names[pos++] = get_full_name();
      for (unsigned i=0;i<sub_timers_.size(); ++i)
        sub_timers_[i].addTimerNames(names, pos);
    }

    double accumulatedTime(const std::string &locate_name="") {

      if (locate_name == "")
        return BaseTimer::accumulatedTime();

      std::string first_name,second_name;

      size_t i = locate_name.find_first_of('@');
      if ( i >= locate_name.size() ) {
        first_name = locate_name;
        second_name = "";
      } else {
        first_name.assign(locate_name,0,i);
        second_name.assign(locate_name,i+1,locate_name.size()-i-1);
      }
      for (unsigned j=0;j<sub_timers_.size();++j)
        if ( first_name == sub_timers_[j].name_)
          return sub_timers_[j].accumulatedTime(second_name);
      return 0;
    }

  protected:
    void splitString(const std::string &locate_name, std::string &first_name, std::string &second_name) {
      size_t i = locate_name.find_first_of('@');
      if ( i >= locate_name.size() ) {
        first_name = locate_name;
        second_name = "";
      } else {
        first_name.assign(locate_name,0,i);
        second_name.assign(locate_name,i+1,locate_name.size()-i-1);
      }
    }

  public:
    double accumulatedTimePerUpdate(const std::string &locate_name="") {

       if (locate_name == "")
         return BaseTimer::accumulatedTimePerUpdate();

       std::string first_name,second_name;
       splitString(locate_name, first_name, second_name);

       for (unsigned j=0;j<sub_timers_.size();j++)
         if ( first_name == sub_timers_[j].name_)
           return sub_timers_[j].accumulatedTimePerUpdate(second_name);
       return 0;
     }

     double accumulatedTimePerTimerCall(const std::string &locate_name="") {

       if (locate_name == "")
         return BaseTimer::accumulatedTimePerTimerCall();

       std::string first_name,second_name;
       splitString(locate_name, first_name, second_name);

       for (unsigned j=0;j<sub_timers_.size();j++)
         if ( first_name == sub_timers_[j].name_)
           return sub_timers_[j].accumulatedTimePerTimerCall(second_name);
       return 0;
     }

     void pack();

     LevelTimer* unpack(unsigned from);

     void report(std::ostream &os);

    BaseTimer::TimeInfo findTimer(const std::string &name,bool& found);

  protected:


  }; // LevelTimer




public:
  explicit StackedTimer(const char *name) :timer_(0,name,NULL,true) {top_ = &timer_;}
  //  ~StackedTimer();
  void start() { 
    timer_.BaseTimer::start();
#if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
    ::Kokkos::Profiling::pushRegion("ANONYMOUS");
#endif
}
  void start(const std::string name) {
    if (top_ == NULL)
      top_ = timer_.start(name.c_str());
    else
      top_ = top_->start(name.c_str());
#if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
    ::Kokkos::Profiling::pushRegion(name);
#endif
  }

  void stop(const std::string &name = "RootTimer") {
    if (top_)
      top_ = top_->stop(name);
    else
      timer_.BaseTimer::stop( );
#if defined(HAVE_TEUCHOS_KOKKOS_PROFILING) && defined(HAVE_TEUCHOSCORE_KOKKOSCORE)
    ::Kokkos::Profiling::popRegion();
#endif
  }

  void incrementCount(int i) {
    top_->incrementCount(i);
  }

  double accumulatedTime(const std::string &name=""){
    if (top_) // Top is null for the head node when nothing is running
      return top_->accumulatedTime(name);
    else
      return timer_.accumulatedTime(name);
  }

  double accumulatedTimePerUpdate(const std::string &name="") {
     if (top_) // Top is null for the head node when nothing is running
       return top_->accumulatedTimePerUpdate(name);
     else
       return timer_.accumulatedTimePerUpdate(name);
   }
  double accumulatedTimePerTimerCall(const std::string &name="") {
     if (top_) // Top is null for the head node when nothing is running
       return top_->accumulatedTimePerTimerCall(name);
     else
       return timer_.accumulatedTimePerTimerCall(name);
   }

  BaseTimer::TimeInfo findTimer(const std::string &name) {
    bool foundTimer = false;
    const auto timeInfo = timer_.findTimer(name,foundTimer);
    TEUCHOS_TEST_FOR_EXCEPTION(!foundTimer, std::runtime_error,
      "StackedTimer::findTimer() failed to find a timer named \"" << name << "\"!\n");
    return timeInfo;
  }

  void report(std::ostream &os) {
    timer_.report(os);
  }

  struct OutputOptions {
    OutputOptions() : output_fraction(false), output_total_updates(false), output_histogram(false),
                      output_minmax(false), num_histogram(10), max_levels(INT_MAX),
                      print_warnings(true) {}
    bool output_fraction;
    bool output_total_updates;
    bool output_histogram;
    bool output_minmax;
    int num_histogram;
    int max_levels;
    bool print_warnings;
  };

  void report(std::ostream &os, Teuchos::RCP<const Teuchos::Comm<int> > comm, OutputOptions options = OutputOptions());


protected:
  LevelTimer *top_;
  LevelTimer timer_;

  Array<std::string> flat_names_;
  Array<double> min_;
  Array<double> max_;
  Array<double> sum_;
  Array<double> sum_sq_;
  Array<Array<int>> hist_;
  Array<unsigned long> count_;
  Array<unsigned long long> updates_;
  Array<int> active_;

   void flatten();

   void merge(Teuchos::RCP<const Teuchos::Comm<int> > comm);

   void collectRemoteData(Teuchos::RCP<const Teuchos::Comm<int> > comm, const OutputOptions &options );

  double printLevel(std::string prefix, int level, std::ostream &os, std::vector<bool> &printed,
                    double parent_time, const OutputOptions &options);

};  //StackedTimer


} //namespace Teuchos

#endif /* TEUCHOS_STACKED_TIMER_HPP */