| [de061d] | 1 | /*
 | 
|---|
 | 2 |  *    vmg - a versatile multigrid solver
 | 
|---|
 | 3 |  *    Copyright (C) 2012 Institute for Numerical Simulation, University of Bonn
 | 
|---|
 | 4 |  *
 | 
|---|
 | 5 |  *  vmg is free software: you can redistribute it and/or modify
 | 
|---|
 | 6 |  *  it under the terms of the GNU General Public License as published by
 | 
|---|
 | 7 |  *  the Free Software Foundation, either version 3 of the License, or
 | 
|---|
 | 8 |  *  (at your option) any later version.
 | 
|---|
 | 9 |  *
 | 
|---|
 | 10 |  *  vmg is distributed in the hope that it will be useful,
 | 
|---|
 | 11 |  *  but WITHOUT ANY WARRANTY; without even the implied warranty of
 | 
|---|
 | 12 |  *  MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 | 
|---|
 | 13 |  *  GNU General Public License for more details.
 | 
|---|
 | 14 |  *
 | 
|---|
 | 15 |  *  You should have received a copy of the GNU General Public License
 | 
|---|
 | 16 |  *  along with this program.  If not, see <http://www.gnu.org/licenses/>.
 | 
|---|
 | 17 |  */
 | 
|---|
 | 18 | 
 | 
|---|
 | 19 | /**
 | 
|---|
 | 20 |  * @file   timer.cpp
 | 
|---|
 | 21 |  * @author Julian Iseringhausen <isering@ins.uni-bonn.de>
 | 
|---|
 | 22 |  * @date   Tue Sep 6 16:17:40 2011
 | 
|---|
 | 23 |  *
 | 
|---|
 | 24 |  * @brief  Class to measure timings.
 | 
|---|
 | 25 |  *
 | 
|---|
 | 26 |  */
 | 
|---|
 | 27 | 
 | 
|---|
 | 28 | #ifdef HAVE_CONFIG_H
 | 
|---|
 | 29 | #include <libvmg_config.h>
 | 
|---|
 | 30 | #endif
 | 
|---|
 | 31 | 
 | 
|---|
 | 32 | #ifdef HAVE_MPI
 | 
|---|
 | 33 | #include <mpi.h>
 | 
|---|
 | 34 | #ifdef HAVE_MARMOT
 | 
|---|
 | 35 | #include <enhancempicalls.h>
 | 
|---|
 | 36 | #include <sourceinfompicalls.h>
 | 
|---|
 | 37 | #endif
 | 
|---|
 | 38 | #endif
 | 
|---|
 | 39 | 
 | 
|---|
 | 40 | #include <iostream>
 | 
|---|
 | 41 | #include <limits>
 | 
|---|
 | 42 | #include <sstream>
 | 
|---|
 | 43 | 
 | 
|---|
 | 44 | #include "base/helper.hpp"
 | 
|---|
 | 45 | #include "base/timer.hpp"
 | 
|---|
 | 46 | #include "comm/comm.hpp"
 | 
|---|
 | 47 | #include "thirdparty/pugixml/pugixml.hpp"
 | 
|---|
 | 48 | #include "mg.hpp"
 | 
|---|
 | 49 | 
 | 
|---|
 | 50 | using namespace VMG;
 | 
|---|
 | 51 | 
 | 
|---|
 | 52 | std::map<std::string, TimerData> Timer::td;
 | 
|---|
 | 53 | 
 | 
|---|
 | 54 | template <class T>
 | 
|---|
 | 55 | static T min(T* data, int num_data, int& at_rank)
 | 
|---|
 | 56 | {
 | 
|---|
 | 57 |   at_rank = 0;
 | 
|---|
 | 58 |   T min = data[0];
 | 
|---|
 | 59 | 
 | 
|---|
 | 60 |   for (int i=1; i<num_data; ++i)
 | 
|---|
 | 61 |     if (data[i] < min) {
 | 
|---|
 | 62 |       at_rank = i;
 | 
|---|
 | 63 |       min = data[i];
 | 
|---|
 | 64 |     }
 | 
|---|
 | 65 |   return min;
 | 
|---|
 | 66 | }
 | 
|---|
 | 67 | 
 | 
|---|
 | 68 | template <class T>
 | 
|---|
 | 69 | static T max(T* data, int num_data, int& at_rank)
 | 
|---|
 | 70 | {
 | 
|---|
 | 71 |   at_rank = 0;
 | 
|---|
 | 72 |   T max = data[0];
 | 
|---|
 | 73 | 
 | 
|---|
 | 74 |   for (int i=1; i<num_data; ++i)
 | 
|---|
 | 75 |     if (data[i] > max) {
 | 
|---|
 | 76 |       at_rank = i;
 | 
|---|
 | 77 |       max = data[i];
 | 
|---|
 | 78 |     }
 | 
|---|
 | 79 |   return max;
 | 
|---|
 | 80 | }
 | 
|---|
 | 81 | 
 | 
|---|
 | 82 | template <class T>
 | 
|---|
 | 83 | static vmg_float avg(T* data, int num_data)
 | 
|---|
 | 84 | {
 | 
|---|
 | 85 |   vmg_float average = 0.0;
 | 
|---|
 | 86 |   vmg_float num_data_inv = 1.0 / static_cast<vmg_float>(num_data);
 | 
|---|
 | 87 |   for (int i=0; i<num_data; ++i)
 | 
|---|
 | 88 |     average += data[i] * num_data_inv;
 | 
|---|
 | 89 |   return average;
 | 
|---|
 | 90 | }
 | 
|---|
 | 91 | 
 | 
|---|
 | 92 | void Timer::Start(std::string event)
 | 
|---|
 | 93 | {
 | 
|---|
 | 94 | #ifdef HAVE_MPI
 | 
|---|
 | 95 | #ifdef OUTPUT_TIMING
 | 
|---|
 | 96 |   std::map<std::string, TimerData>::iterator iter = td.find(event);
 | 
|---|
 | 97 |   if (iter == td.end())
 | 
|---|
 | 98 |     iter = td.insert(std::make_pair(event, TimerData())).first;
 | 
|---|
 | 99 | 
 | 
|---|
 | 100 |   iter->second.time_start = MPI_Wtime();
 | 
|---|
 | 101 | #endif
 | 
|---|
 | 102 | #endif
 | 
|---|
 | 103 | }
 | 
|---|
 | 104 | 
 | 
|---|
 | 105 | void Timer::Stop(std::string event)
 | 
|---|
 | 106 | {
 | 
|---|
 | 107 | #ifdef HAVE_MPI
 | 
|---|
 | 108 | #ifdef OUTPUT_TIMING
 | 
|---|
 | 109 |   double time_end = MPI_Wtime();
 | 
|---|
 | 110 | 
 | 
|---|
 | 111 |   std::map<std::string, TimerData>::iterator iter = td.find(event);
 | 
|---|
 | 112 | 
 | 
|---|
 | 113 |   if (time_end - iter->second.time_start < std::numeric_limits<double>::min())
 | 
|---|
 | 114 |     ++(iter->second.warning);
 | 
|---|
 | 115 | 
 | 
|---|
 | 116 |   ++(iter->second.total);
 | 
|---|
 | 117 | 
 | 
|---|
 | 118 |   iter->second.duration += time_end - iter->second.time_start;
 | 
|---|
 | 119 | #endif
 | 
|---|
 | 120 | #endif
 | 
|---|
 | 121 | }
 | 
|---|
 | 122 | 
 | 
|---|
 | 123 | void Timer::Clear()
 | 
|---|
 | 124 | {
 | 
|---|
 | 125 |   td.clear();
 | 
|---|
 | 126 | }
 | 
|---|
 | 127 | 
 | 
|---|
 | 128 | pugi::xml_node Timer::ToXMLNode()
 | 
|---|
 | 129 | {
 | 
|---|
 | 130 |  std::map<std::string, TimerData>::iterator iter;
 | 
|---|
 | 131 | 
 | 
|---|
 | 132 |  pugi::xml_node node_process;
 | 
|---|
 | 133 |  node_process.append_attribute("Rank").set_value(MG::GetComm()->GlobalRank());
 | 
|---|
 | 134 | 
 | 
|---|
 | 135 |  pugi::xml_node node_timings = node_process.append_child("Timings");
 | 
|---|
 | 136 | 
 | 
|---|
 | 137 |  for (iter=Timer::td.begin(); iter!=Timer::td.end(); ++iter) {
 | 
|---|
 | 138 | 
 | 
|---|
 | 139 |    pugi::xml_node node_entry = node_timings.append_child("Sample");
 | 
|---|
 | 140 |    node_entry.append_attribute("Name").set_value(Helper::ToString(iter->first).c_str());
 | 
|---|
 | 141 | 
 | 
|---|
 | 142 |    node_entry.append_child("Duration")
 | 
|---|
 | 143 |      .append_child(pugi::node_pcdata)
 | 
|---|
 | 144 |      .set_value(Helper::ToString(iter->second.duration).c_str());
 | 
|---|
 | 145 | 
 | 
|---|
 | 146 |    node_entry.append_child("Warnings")
 | 
|---|
 | 147 |      .append_child(pugi::node_pcdata)
 | 
|---|
 | 148 |      .set_value(Helper::ToString(iter->second.warning).c_str());
 | 
|---|
 | 149 | 
 | 
|---|
 | 150 |    node_entry.append_child("Total")
 | 
|---|
 | 151 |      .append_child(pugi::node_pcdata)
 | 
|---|
 | 152 |      .set_value(Helper::ToString(iter->second.total).c_str());
 | 
|---|
 | 153 | 
 | 
|---|
 | 154 |  }
 | 
|---|
 | 155 | 
 | 
|---|
 | 156 |  return node_process;
 | 
|---|
 | 157 | }
 | 
|---|
 | 158 | 
 | 
|---|
 | 159 | std::string Timer::ToString()
 | 
|---|
 | 160 | {
 | 
|---|
 | 161 |   pugi::xml_node node = Timer::ToXMLNode();
 | 
|---|
 | 162 |   std::stringstream str;
 | 
|---|
 | 163 |   node.print(str);
 | 
|---|
 | 164 |   return str.str();
 | 
|---|
 | 165 | }
 | 
|---|
 | 166 | 
 | 
|---|
 | 167 | void Timer::Print()
 | 
|---|
 | 168 | {
 | 
|---|
 | 169 | #ifdef OUTPUT_TIMING
 | 
|---|
 | 170 |   Comm& comm = *MG::GetComm();
 | 
|---|
 | 171 |   if (comm.GlobalRank() == 0) {
 | 
|---|
 | 172 |     std::map<std::string, TimerData>::const_iterator iter;
 | 
|---|
 | 173 |     comm.PrintOnce(Timing, "Running times:");
 | 
|---|
 | 174 |     for (iter=Timer::td.begin(); iter!=Timer::td.end(); ++iter)
 | 
|---|
 | 175 |       comm.PrintOnce(Timing, "  %s: %e s (%d)", iter->first.c_str(), iter->second.duration, iter->second.total);
 | 
|---|
 | 176 |   }
 | 
|---|
 | 177 | #endif
 | 
|---|
 | 178 | }
 | 
|---|
 | 179 | void Timer::PrintGlobal()
 | 
|---|
 | 180 | {
 | 
|---|
 | 181 | #ifdef OUTPUT_TIMING
 | 
|---|
 | 182 |   std::map<std::string, TimerData>::const_iterator iter;
 | 
|---|
 | 183 |   Comm& comm = *MG::GetComm();
 | 
|---|
 | 184 |   char name[80];
 | 
|---|
 | 185 | 
 | 
|---|
 | 186 |   int rank = comm.GlobalRank();
 | 
|---|
 | 187 |   int size = comm.GlobalSize();
 | 
|---|
 | 188 | 
 | 
|---|
 | 189 |   vmg_float times[size];
 | 
|---|
 | 190 |   int calls[size];
 | 
|---|
 | 191 | 
 | 
|---|
 | 192 |   comm.PrintOnce(Timing, "Running times (global):");
 | 
|---|
 | 193 | 
 | 
|---|
 | 194 |   int timer_size = Timer::td.size();
 | 
|---|
 | 195 |   comm.GlobalBroadcast(timer_size);
 | 
|---|
 | 196 | 
 | 
|---|
 | 197 |   if (rank == 0) {
 | 
|---|
 | 198 |       for (iter=Timer::td.begin(); iter!=Timer::td.end(); ++iter) {
 | 
|---|
 | 199 |         std::strcpy(name, iter->first.c_str());
 | 
|---|
 | 200 |         comm.GlobalBroadcast(name);
 | 
|---|
 | 201 |         comm.GlobalGather(Timer::td[name].duration, times);
 | 
|---|
 | 202 |         comm.GlobalGather(Timer::td[name].total, calls);
 | 
|---|
 | 203 | 
 | 
|---|
 | 204 |         int min_calls, max_calls;
 | 
|---|
 | 205 |         vmg_float avg_calls;
 | 
|---|
 | 206 |         vmg_float min_duration, max_duration, avg_duration;
 | 
|---|
 | 207 |         int rank_min_calls, rank_max_calls, rank_min_duration, rank_max_duration;
 | 
|---|
 | 208 | 
 | 
|---|
 | 209 |         min_duration = min(times, size, rank_min_duration);
 | 
|---|
 | 210 |         max_duration = max(times, size, rank_max_duration);
 | 
|---|
 | 211 |         avg_duration = avg(times, size);
 | 
|---|
 | 212 |         min_calls = min(calls, size, rank_min_calls);
 | 
|---|
 | 213 |         max_calls = max(calls, size, rank_max_calls);
 | 
|---|
 | 214 |         avg_calls = avg(calls, size);
 | 
|---|
 | 215 | 
 | 
|---|
 | 216 |         comm.PrintOnce(Timing, "  %s: %e s (%d)", iter->first.c_str(), iter->second.duration, iter->second.total);
 | 
|---|
 | 217 |         comm.PrintOnce(Timing, "    Min: %e s @ %d", min_duration, rank_min_duration);
 | 
|---|
 | 218 |         comm.PrintOnce(Timing, "    Max: %e s @ %d", max_duration, rank_max_duration);
 | 
|---|
 | 219 |         comm.PrintOnce(Timing, "    Avg: %e s", avg_duration);
 | 
|---|
 | 220 |         comm.PrintOnce(Timing, "    Min calls: %d @ %d", min_calls, rank_min_calls);
 | 
|---|
 | 221 |         comm.PrintOnce(Timing, "    Max calls: %d @ %d", max_calls, rank_max_calls);
 | 
|---|
 | 222 |         comm.PrintOnce(Timing, "    Avg calls: %f", avg_calls);
 | 
|---|
 | 223 |     }
 | 
|---|
 | 224 |   }else {
 | 
|---|
 | 225 |     for (int i=0; i<timer_size; ++i) {
 | 
|---|
 | 226 |       comm.GlobalBroadcast(name);
 | 
|---|
 | 227 |       comm.GlobalGather(Timer::td[name].duration, times);
 | 
|---|
 | 228 |       comm.GlobalGather(Timer::td[name].total, calls);
 | 
|---|
 | 229 |     }
 | 
|---|
 | 230 |   }
 | 
|---|
 | 231 | 
 | 
|---|
 | 232 | #endif
 | 
|---|
 | 233 | }
 | 
|---|
 | 234 | 
 | 
|---|
 | 235 | std::ostream& VMG::operator<<(std::ostream& out, const Timer&)
 | 
|---|
 | 236 | {
 | 
|---|
 | 237 |   return out << Timer::ToString();
 | 
|---|
 | 238 | }
 | 
|---|