| [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 | } | 
|---|