/** * @file timer.cpp * @author Julian Iseringhausen * @date Tue Sep 6 16:17:40 2011 * * @brief Class to measure timings. * */ #ifdef HAVE_CONFIG_H #include #endif #ifdef HAVE_MPI #include #ifdef HAVE_MARMOT #include #include #endif #endif #include #include #include #include "base/helper.hpp" #include "base/timer.hpp" #include "comm/comm.hpp" #include "thirdparty/pugixml/pugixml.hpp" #include "mg.hpp" using namespace VMG; std::map Timer::td; void Timer::Start(std::string event) { #ifdef HAVE_MPI #ifdef DEBUG_MEASURE_TIME std::map::iterator iter = td.find(event); if (iter == td.end()) iter = td.insert(std::make_pair(event, TimerData())).first; iter->second.time_start = MPI_Wtime(); #endif #endif } void Timer::Stop(std::string event) { #ifdef HAVE_MPI #ifdef DEBUG_MEASURE_TIME double time_end = MPI_Wtime(); std::map::iterator iter = td.find(event); if (time_end - iter->second.time_start < std::numeric_limits::min()) ++(iter->second.warning); ++(iter->second.total); iter->second.duration += time_end - iter->second.time_start; #endif #endif } void Timer::Clear() { td.clear(); } pugi::xml_node Timer::ToXMLNode() { std::map::iterator iter; pugi::xml_node node_process; node_process.append_attribute("Rank").set_value(MG::GetComm()->GlobalRank()); pugi::xml_node node_timings = node_process.append_child("Timings"); for (iter=Timer::td.begin(); iter!=Timer::td.end(); ++iter) { pugi::xml_node node_entry = node_timings.append_child("Sample"); node_entry.append_attribute("Name").set_value(Helper::ToString(iter->first).c_str()); node_entry.append_child("Duration") .append_child(pugi::node_pcdata) .set_value(Helper::ToString(iter->second.duration).c_str()); node_entry.append_child("Warnings") .append_child(pugi::node_pcdata) .set_value(Helper::ToString(iter->second.warning).c_str()); node_entry.append_child("Total") .append_child(pugi::node_pcdata) .set_value(Helper::ToString(iter->second.total).c_str()); } return node_process; } std::string Timer::ToString() { pugi::xml_node node = Timer::ToXMLNode(); std::stringstream str; node.print(str); return str.str(); } void Timer::Print() { #ifdef DEBUG_MEASURE_TIME std::map::const_iterator iter; Comm& comm = *MG::GetComm(); if (comm.GlobalRank() == 0) { comm.PrintStringOnce("Running times:"); for (iter=Timer::td.begin(); iter!=Timer::td.end(); ++iter) comm.PrintStringOnce(" %s: %e s (%d)", iter->first.c_str(), iter->second.duration, iter->second.total); } #endif } template static T min(T* data, int num_data, int& at_rank) { at_rank = 0; T min = data[0]; for (int i=1; i static T max(T* data, int num_data, int& at_rank) { at_rank = 0; T max = data[0]; for (int i=1; i max) { at_rank = i; max = data[i]; } return max; } template static vmg_float avg(T* data, int num_data) { vmg_float average = 0.0; vmg_float num_data_inv = 1.0 / static_cast(num_data); for (int i=0; i::const_iterator iter; Comm& comm = *MG::GetComm(); char name[80]; int rank, size; MPI_Comm_rank(MPI_COMM_WORLD, &rank); MPI_Comm_size(MPI_COMM_WORLD, &size); vmg_float times[size]; int calls[size]; comm.PrintStringOnce("Running times (global):"); for (iter=Timer::td.begin(); iter!=Timer::td.end(); ++iter) { std::strcpy(name, iter->first.c_str()); MPI_Bcast(name, 80, MPI_CHAR, 0, MPI_COMM_WORLD); MPI_Gather(&Timer::td[name].duration, 1, MPI_DOUBLE, times, 1, MPI_DOUBLE, 0, MPI_COMM_WORLD); MPI_Gather(&Timer::td[name].total, 1, MPI_INT, calls, 1, MPI_INT, 0, MPI_COMM_WORLD); if (rank == 0) { int min_calls, max_calls, avg_calls; vmg_float min_duration, max_duration, avg_duration; int rank_min_calls, rank_max_calls, rank_min_duration, rank_max_duration; min_duration = min(times, size, rank_min_duration); max_duration = max(times, size, rank_max_duration); avg_duration = avg(times, size); min_calls = min(calls, size, rank_min_calls); max_calls = max(calls, size, rank_max_calls); avg_calls = avg(calls, size); comm.PrintStringOnce(" %s: %e s (%d)", iter->first.c_str(), iter->second.duration, iter->second.total); comm.PrintStringOnce(" Min: %e s @ %d", min_duration, rank_min_duration); comm.PrintStringOnce(" Max: %e s @ %d", max_duration, rank_max_duration); comm.PrintStringOnce(" Avg: %e s", avg_duration); comm.PrintStringOnce(" Min calls: %d @ %d", min_calls, rank_min_calls); comm.PrintStringOnce(" Max calls: %d @ %d", max_calls, rank_max_calls); comm.PrintStringOnce(" Avg calls: %f", avg_calls); } } #endif } std::ostream& VMG::operator<<(std::ostream& out, const Timer&) { return out << Timer::ToString(); }