Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
30 changes: 22 additions & 8 deletions src/oops/util/Timer.cc
Original file line number Diff line number Diff line change
Expand Up @@ -25,22 +25,36 @@ static int nested_timers = 0; // Only non-nested timers count towards measured
// -----------------------------------------------------------------------------

Timer::Timer(const std::string & class_name, const std::string & method_name)
: name_(class_name + "::" + method_name), start_()
: name_(class_name + "::" + method_name), start_(), stopped_(false)
{
++nested_timers;
start_ = ClockT::now();
// create a new node in timer tree
TimerHelper::setCurrentTree(TimerHelper::getCurrentTree()->goDown(name_));
}

void Timer::stop() {
if (!stopped_) {
stopped_ = true;
std::chrono::duration<double, std::milli> dt = ClockT::now() - start_; // elapsed millisecs
--nested_timers;
// A top-level timer is created (when nested_timers == 0) in TimerHelper::start() for total time.
// To count measured time (and establish timer coverage), we sum times from the timers 1 level
// below this top-level timer. More-deeply nested timers would duplicate time if included.
const bool include_timer_in_sum = (nested_timers == 1);
TimerHelper::add(name_, dt.count(), include_timer_in_sum);
// time will be added in tree strcture anyway
TimerHelper::getCurrentTree()->addTime(dt.count());
TimerHelper::setCurrentTree(TimerHelper::getCurrentTree()->goUp());
}
}

// -----------------------------------------------------------------------------

Timer::~Timer() {
std::chrono::duration<double, std::milli> dt = ClockT::now() - start_; // elapsed millisecs
--nested_timers;
// A top-level timer is created (when nested_timers == 0) in TimerHelper::start() for total time.
// To count measured time (and establish timer coverage), we sum times from the timers 1 level
// below this top-level timer. More-deeply nested timers would duplicate time if included.
const bool include_timer_in_sum = (nested_timers == 1);
TimerHelper::add(name_, dt.count(), include_timer_in_sum);
if (!stopped_) {
stop();
}
}

// -----------------------------------------------------------------------------
Expand Down
3 changes: 3 additions & 0 deletions src/oops/util/Timer.h
Original file line number Diff line number Diff line change
Expand Up @@ -28,9 +28,12 @@ class Timer {

Timer(const Timer&) = delete; // Non-copyable

void stop();

private:
std::string name_;
TimeT start_;
bool stopped_;
};

// -----------------------------------------------------------------------------
Expand Down
32 changes: 32 additions & 0 deletions src/oops/util/TimerHelper.cc
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,9 @@

namespace util {

TimerTree* TimerHelper::ttree_ptr_root_ = nullptr;
TimerTree* TimerHelper::ttree_ptr_current_ = nullptr;

// -----------------------------------------------------------------------------

TimerHelper & TimerHelper::getHelper() {
Expand All @@ -35,6 +38,8 @@ TimerHelper & TimerHelper::getHelper() {

void TimerHelper::start() {
getHelper().on_ = true;
getHelper().ttree_ptr_root_ = new TimerTree("root");
getHelper().ttree_ptr_current_ = getHelper().ttree_ptr_root_;
getHelper().total_.reset(new Timer("util::Timers", "Total"));
getHelper().timers_["util::Timers::measured"] = 0.0;
getHelper().counts_["util::Timers::measured"] = 1;
Expand All @@ -48,6 +53,9 @@ void TimerHelper::stop() {
getHelper().timers_.clear();
getHelper().counts_.clear();
getHelper().on_ = false;
delete getHelper().ttree_ptr_root_;
getHelper().ttree_ptr_root_ = nullptr;
getHelper().ttree_ptr_current_ = nullptr;
}

// -----------------------------------------------------------------------------
Expand Down Expand Up @@ -185,8 +193,32 @@ void TimerHelper::print(std::ostream & os) const {
os << std::string(std::floor(title_half_width), '-')
<< title << std::string(std::ceil(title_half_width), '-') << std::endl;
}

// Print hierarchical timer tree structure
if (ttree_ptr_root_ != nullptr) {
os << std::endl;
os << std::string(table_width, '-') << std::endl;
std::string tree_title = " Hierarchical Timer Tree";
float tree_title_half_width = (table_width - tree_title.size()) / 2.;
os << std::string(std::floor(tree_title_half_width), '-')
<< tree_title << std::string(std::ceil(tree_title_half_width), '-') << std::endl;
os << std::string(table_width, '-') << std::endl;

// Print the tree structure starting from root
ttree_ptr_root_->printTree(os);

os << std::string(table_width, '-') << std::endl;
}

}

TimerTree* TimerHelper::getCurrentTree() {
return ttree_ptr_current_;
}

void TimerHelper::setCurrentTree(TimerTree* ttree) {
ttree_ptr_current_ = ttree;
}
// -----------------------------------------------------------------------------

} // namespace util
5 changes: 5 additions & 0 deletions src/oops/util/TimerHelper.h
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
#include "eckit/mpi/Comm.h"
#include "oops/mpi/mpi.h"
#include "oops/util/Printable.h"
#include "oops/util/TimerTree.h"

namespace util {
class Timer;
Expand All @@ -35,10 +36,14 @@ class TimerHelper : public util::Printable,
static void add(const std::string &, const double, const bool);
// const std::chrono::duration<double> &);
static void setComm(const eckit::mpi::Comm & comm);
static TimerTree* getCurrentTree();
static void setCurrentTree(TimerTree* ttree);
~TimerHelper();

private:
static TimerHelper & getHelper();
static TimerTree* ttree_ptr_root_;
static TimerTree* ttree_ptr_current_;
TimerHelper();
void print(std::ostream &) const;

Expand Down
68 changes: 68 additions & 0 deletions src/oops/util/TimerTree.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,68 @@
#ifndef OOPS_UTIL_TIMER_TREE_H_
#define OOPS_UTIL_TIMER_TREE_H_

#include <string>
#include <vector>
#include <map>
#include <iostream>
#include <iomanip>

#include "oops/util/Timer.h"

namespace util {

class TimerTree {
public:
TimerTree(const std::string & name): name_(name), time_count_(0), called_count_(0), parent_(nullptr) {}
~TimerTree() {
for (std::map<std::string, TimerTree*>::iterator it = children_.begin(); it != children_.end(); ++it) {
delete it->second;
}
}
TimerTree* goDown(const std::string & name) {
if (children_.find(name) == children_.end()) {
children_[name] = new TimerTree(name);
children_[name]->parent_ = this;
}
return children_[name];
}
TimerTree* goUp() {
return parent_;
}
void addTime(const int time) {
time_count_ += time;
++called_count_;
}

// Print hierarchical tree structure like Unix 'tree' command
void printTree(std::ostream& os, const std::string& prefix = "", bool isLast = true) const {
// Print current node
os << prefix;
os << (isLast ? "└── " : "├── ");
os << name_ << " (" << std::fixed << std::setprecision(2) << time_count_ << " ms, "
<< called_count_ << " calls)" << std::endl;

// Print children
if (!children_.empty()) {
auto it = children_.begin();
for (size_t i = 0; i < children_.size(); ++i, ++it) {
bool childIsLast = (i == children_.size() - 1);
std::string childPrefix = prefix + (isLast ? " " : "│ ");
it->second->printTree(os, childPrefix, childIsLast);
}
}
}

private:
std::string name_;
int time_count_, called_count_;
TimerTree* parent_;
std::map<std::string, TimerTree*> children_;
};
}





#endif // OOPS_UTIL_TIMER_TREE_H_