Line |
Branch |
Exec |
Source |
1 |
|
|
/////////////////////////////////////////////////////////////////////////////// |
2 |
|
|
// Copyright (c) 2010-2013 Tommaso Urli (tommaso.urli@uniud.it; University of |
3 |
|
|
// Udine) |
4 |
|
|
// |
5 |
|
|
// Permission is hereby granted, free of charge, to any person obtaining |
6 |
|
|
// a copy of this software and associated documentation files (the |
7 |
|
|
// "Software"), to deal in the Software without restriction, including |
8 |
|
|
// without limitation the rights to use, copy, modify, merge, publish, |
9 |
|
|
// distribute, sublicense, and/or sell copies of the Software, and to |
10 |
|
|
// permit persons to whom the Software is furnished to do so, subject to |
11 |
|
|
// the following conditions: |
12 |
|
|
// |
13 |
|
|
// The above copyright notice and this permission notice shall be |
14 |
|
|
// included in all copies or substantial portions of the Software. |
15 |
|
|
// |
16 |
|
|
// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, |
17 |
|
|
// EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF |
18 |
|
|
// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND |
19 |
|
|
// NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE |
20 |
|
|
// LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION |
21 |
|
|
// OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION |
22 |
|
|
// WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE. |
23 |
|
|
/////////////////////////////////////////////////////////////////////////////// |
24 |
|
|
|
25 |
|
|
#ifndef WIN32 |
26 |
|
|
#include <sys/time.h> |
27 |
|
|
#else |
28 |
|
|
#include <Windows.h> |
29 |
|
|
|
30 |
|
|
#include <iomanip> |
31 |
|
|
#endif |
32 |
|
|
|
33 |
|
|
#include <iomanip> // std::setprecision |
34 |
|
|
|
35 |
|
|
#include "crocoddyl/core/utils/stop-watch.hpp" |
36 |
|
|
|
37 |
|
|
using std::map; |
38 |
|
|
using std::ostringstream; |
39 |
|
|
using std::string; |
40 |
|
|
|
41 |
|
|
namespace crocoddyl { |
42 |
|
|
|
43 |
|
✗ |
Stopwatch& getProfiler() { |
44 |
|
✗ |
static Stopwatch s(REAL_TIME); // alternatives are CPU_TIME and REAL_TIME |
45 |
|
✗ |
return s; |
46 |
|
|
} |
47 |
|
|
|
48 |
|
✗ |
Stopwatch::Stopwatch(StopwatchMode _mode) |
49 |
|
✗ |
: active(true), mode(_mode), profiler_active(false) { |
50 |
|
✗ |
records_of = new map<string, PerformanceData>(); |
51 |
|
|
} |
52 |
|
|
|
53 |
|
✗ |
Stopwatch::~Stopwatch() { delete records_of; } |
54 |
|
|
|
55 |
|
✗ |
void Stopwatch::enable_profiler() { profiler_active = true; } |
56 |
|
|
|
57 |
|
✗ |
void Stopwatch::disable_profiler() { profiler_active = false; } |
58 |
|
|
|
59 |
|
✗ |
void Stopwatch::set_mode(StopwatchMode new_mode) { mode = new_mode; } |
60 |
|
|
|
61 |
|
✗ |
bool Stopwatch::performance_exists(string perf_name) { |
62 |
|
✗ |
return (records_of->find(perf_name) != records_of->end()); |
63 |
|
|
} |
64 |
|
|
|
65 |
|
✗ |
long double Stopwatch::take_time() { |
66 |
|
✗ |
if (mode == CPU_TIME) { |
67 |
|
|
// Use ctime |
68 |
|
✗ |
return (long double)clock(); |
69 |
|
✗ |
} else if (mode == REAL_TIME) { |
70 |
|
|
// Query operating system |
71 |
|
|
|
72 |
|
|
#ifdef WIN32 |
73 |
|
|
/* In case of usage under Windows */ |
74 |
|
|
FILETIME ft; |
75 |
|
|
LARGE_INTEGER intervals; |
76 |
|
|
|
77 |
|
|
// Get the amount of 100 nanoseconds intervals elapsed since January 1, 1601 |
78 |
|
|
// (UTC) |
79 |
|
|
GetSystemTimeAsFileTime(&ft); |
80 |
|
|
intervals.LowPart = ft.dwLowDateTime; |
81 |
|
|
intervals.HighPart = ft.dwHighDateTime; |
82 |
|
|
|
83 |
|
|
long double measure = intervals.QuadPart; |
84 |
|
|
measure -= 116444736000000000.0; // Convert to UNIX epoch time |
85 |
|
|
measure /= 10000000.0; // Convert to seconds |
86 |
|
|
|
87 |
|
|
return measure; |
88 |
|
|
#else |
89 |
|
|
/* Linux, MacOS, ... */ |
90 |
|
|
struct timeval tv; |
91 |
|
✗ |
gettimeofday(&tv, NULL); |
92 |
|
|
|
93 |
|
✗ |
long double measure = tv.tv_usec; |
94 |
|
✗ |
measure /= 1000000.0; // Convert to seconds |
95 |
|
✗ |
measure += (long double)tv.tv_sec; // Add seconds part |
96 |
|
✗ |
return measure; |
97 |
|
|
#endif |
98 |
|
|
|
99 |
|
|
} else { |
100 |
|
|
// If mode == NONE, clock has not been initialized, then throw exception |
101 |
|
✗ |
throw StopwatchException("Clock not initialized to a time taking mode!"); |
102 |
|
|
} |
103 |
|
|
} |
104 |
|
|
|
105 |
|
✗ |
Stopwatch::PerformanceData& Stopwatch::get_or_create_perf( |
106 |
|
|
const string& perf_name) { |
107 |
|
✗ |
const auto it = records_of->insert(make_pair(perf_name, PerformanceData())); |
108 |
|
✗ |
return it.first->second; |
109 |
|
|
} |
110 |
|
|
|
111 |
|
✗ |
void Stopwatch::start(const string& perf_name) { |
112 |
|
✗ |
if (!active) return; |
113 |
|
|
|
114 |
|
✗ |
PerformanceData& perf_info = get_or_create_perf(perf_name); |
115 |
|
|
|
116 |
|
|
// Take ctime |
117 |
|
✗ |
perf_info.clock_start = take_time(); |
118 |
|
|
|
119 |
|
|
// If this is a new start (i.e. not a restart) |
120 |
|
|
// if (!perf_info.paused) |
121 |
|
|
// perf_info.last_time = 0; |
122 |
|
|
|
123 |
|
✗ |
perf_info.paused = false; |
124 |
|
|
} |
125 |
|
|
|
126 |
|
✗ |
void Stopwatch::stop(const string& perf_name) { |
127 |
|
✗ |
if (!active) return; |
128 |
|
|
|
129 |
|
✗ |
long double clock_end = take_time(); |
130 |
|
|
|
131 |
|
|
// Try to recover performance data |
132 |
|
✗ |
if (!performance_exists(perf_name)) |
133 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
134 |
|
|
|
135 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
136 |
|
|
|
137 |
|
✗ |
stop_perf(perf_info, clock_end); |
138 |
|
|
} |
139 |
|
|
|
140 |
|
✗ |
void Stopwatch::stop_perf(PerformanceData& perf_info, long double clock_end) { |
141 |
|
|
// check whether the performance has been reset |
142 |
|
✗ |
if (perf_info.clock_start == 0) return; |
143 |
|
|
|
144 |
|
✗ |
perf_info.stops++; |
145 |
|
✗ |
long double lapse = clock_end - perf_info.clock_start; |
146 |
|
|
|
147 |
|
✗ |
if (mode == CPU_TIME) lapse /= (double)CLOCKS_PER_SEC; |
148 |
|
|
|
149 |
|
|
// Update last time |
150 |
|
✗ |
perf_info.last_time = lapse; |
151 |
|
|
|
152 |
|
|
// Update min/max time |
153 |
|
✗ |
if (lapse >= perf_info.max_time) |
154 |
|
✗ |
perf_info.max_time = lapse; |
155 |
|
✗ |
else if (lapse <= perf_info.min_time) |
156 |
|
✗ |
perf_info.min_time = lapse; |
157 |
|
|
|
158 |
|
|
// Update total time |
159 |
|
✗ |
perf_info.total_time += lapse; |
160 |
|
|
} |
161 |
|
|
|
162 |
|
✗ |
void Stopwatch::pause(const string& perf_name) { |
163 |
|
✗ |
if (!active) return; |
164 |
|
|
|
165 |
|
✗ |
long double clock_end = (long double)clock(); |
166 |
|
|
|
167 |
|
|
// Try to recover performance data |
168 |
|
✗ |
if (!performance_exists(perf_name)) |
169 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
170 |
|
|
|
171 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
172 |
|
|
|
173 |
|
|
// check whether the performance has been reset |
174 |
|
✗ |
if (perf_info.clock_start == 0) return; |
175 |
|
|
|
176 |
|
✗ |
long double lapse = clock_end - perf_info.clock_start; |
177 |
|
|
|
178 |
|
|
// Update total time |
179 |
|
✗ |
perf_info.last_time += lapse; |
180 |
|
✗ |
perf_info.total_time += lapse; |
181 |
|
|
} |
182 |
|
|
|
183 |
|
✗ |
void Stopwatch::reset_all() { |
184 |
|
✗ |
if (!active) return; |
185 |
|
|
|
186 |
|
✗ |
map<string, PerformanceData>::iterator it; |
187 |
|
|
|
188 |
|
✗ |
for (it = records_of->begin(); it != records_of->end(); ++it) { |
189 |
|
✗ |
reset(it->first); |
190 |
|
|
} |
191 |
|
|
} |
192 |
|
|
|
193 |
|
✗ |
void Stopwatch::report_all(int precision, std::ostream& output) { |
194 |
|
✗ |
if (!active) return; |
195 |
|
|
|
196 |
|
|
output << "\n" |
197 |
|
✗ |
<< std::setw(STOP_WATCH_MAX_NAME_LENGTH) << std::left |
198 |
|
✗ |
<< "*** PROFILING RESULTS [ms] "; |
199 |
|
|
output << std::setw(STOP_WATCH_TIME_WIDTH) << "min" |
200 |
|
✗ |
<< " "; |
201 |
|
|
output << std::setw(STOP_WATCH_TIME_WIDTH) << "avg" |
202 |
|
✗ |
<< " "; |
203 |
|
|
output << std::setw(STOP_WATCH_TIME_WIDTH) << "max" |
204 |
|
✗ |
<< " "; |
205 |
|
|
output << std::setw(STOP_WATCH_TIME_WIDTH) << "lastTime" |
206 |
|
✗ |
<< " "; |
207 |
|
|
output << std::setw(STOP_WATCH_TIME_WIDTH) << "nSamples" |
208 |
|
✗ |
<< " "; |
209 |
|
|
output << std::setw(STOP_WATCH_TIME_WIDTH) << "totalTime" |
210 |
|
✗ |
<< " ***\n" |
211 |
|
✗ |
<< std::flush; |
212 |
|
✗ |
map<string, PerformanceData>::iterator it; |
213 |
|
✗ |
for (it = records_of->begin(); it != records_of->end(); ++it) { |
214 |
|
✗ |
if (it->second.stops > 0) report(it->first, precision, output); |
215 |
|
|
} |
216 |
|
|
} |
217 |
|
|
|
218 |
|
✗ |
void Stopwatch::reset(const string& perf_name) { |
219 |
|
✗ |
if (!active) return; |
220 |
|
|
|
221 |
|
|
// Try to recover performance data |
222 |
|
✗ |
if (!performance_exists(perf_name)) |
223 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
224 |
|
|
|
225 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
226 |
|
|
|
227 |
|
✗ |
perf_info.clock_start = 0; |
228 |
|
✗ |
perf_info.total_time = 0; |
229 |
|
✗ |
perf_info.min_time = 0; |
230 |
|
✗ |
perf_info.max_time = 0; |
231 |
|
✗ |
perf_info.last_time = 0; |
232 |
|
✗ |
perf_info.paused = false; |
233 |
|
✗ |
perf_info.stops = 0; |
234 |
|
|
} |
235 |
|
|
|
236 |
|
✗ |
void Stopwatch::turn_on() { |
237 |
|
✗ |
std::cout << "Stopwatch active." << std::endl; |
238 |
|
✗ |
active = true; |
239 |
|
|
} |
240 |
|
|
|
241 |
|
✗ |
void Stopwatch::turn_off() { |
242 |
|
✗ |
std::cout << "Stopwatch inactive." << std::endl; |
243 |
|
✗ |
active = false; |
244 |
|
|
} |
245 |
|
|
|
246 |
|
✗ |
void Stopwatch::report(const string& perf_name, int precision, |
247 |
|
|
std::ostream& output) { |
248 |
|
✗ |
if (!active) return; |
249 |
|
|
|
250 |
|
|
// Try to recover performance data |
251 |
|
✗ |
if (!performance_exists(perf_name)) |
252 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
253 |
|
|
|
254 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
255 |
|
|
|
256 |
|
✗ |
output << std::setw(STOP_WATCH_MAX_NAME_LENGTH) << std::left << perf_name; |
257 |
|
✗ |
output << std::fixed << std::setprecision(precision) |
258 |
|
✗ |
<< std::setw(STOP_WATCH_TIME_WIDTH) << (perf_info.min_time * 1e3) |
259 |
|
✗ |
<< " "; |
260 |
|
✗ |
output << std::fixed << std::setprecision(precision) |
261 |
|
✗ |
<< std::setw(STOP_WATCH_TIME_WIDTH) |
262 |
|
✗ |
<< (perf_info.total_time * 1e3 / (long double)perf_info.stops) << " "; |
263 |
|
✗ |
output << std::fixed << std::setprecision(precision) |
264 |
|
✗ |
<< std::setw(STOP_WATCH_TIME_WIDTH) << (perf_info.max_time * 1e3) |
265 |
|
✗ |
<< " "; |
266 |
|
✗ |
output << std::fixed << std::setprecision(precision) |
267 |
|
✗ |
<< std::setw(STOP_WATCH_TIME_WIDTH) << (perf_info.last_time * 1e3) |
268 |
|
✗ |
<< " "; |
269 |
|
✗ |
output << std::fixed << std::setprecision(precision) |
270 |
|
✗ |
<< std::setw(STOP_WATCH_TIME_WIDTH) << perf_info.stops << " "; |
271 |
|
✗ |
output << std::fixed << std::setprecision(precision) |
272 |
|
✗ |
<< std::setw(STOP_WATCH_TIME_WIDTH) << perf_info.total_time * 1e3 |
273 |
|
✗ |
<< std::endl |
274 |
|
✗ |
<< std::flush; |
275 |
|
|
} |
276 |
|
|
|
277 |
|
✗ |
long double Stopwatch::get_time_so_far(const string& perf_name) { |
278 |
|
|
// Try to recover performance data |
279 |
|
✗ |
if (!performance_exists(perf_name)) |
280 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
281 |
|
|
|
282 |
|
|
long double lapse = |
283 |
|
✗ |
(take_time() - (records_of->find(perf_name)->second).clock_start); |
284 |
|
|
|
285 |
|
✗ |
if (mode == CPU_TIME) lapse /= (double)CLOCKS_PER_SEC; |
286 |
|
|
|
287 |
|
✗ |
return lapse; |
288 |
|
|
} |
289 |
|
|
|
290 |
|
✗ |
long double Stopwatch::get_total_time(const string& perf_name) { |
291 |
|
|
// Try to recover performance data |
292 |
|
✗ |
if (!performance_exists(perf_name)) |
293 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
294 |
|
|
|
295 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
296 |
|
|
|
297 |
|
✗ |
return perf_info.total_time; |
298 |
|
|
} |
299 |
|
|
|
300 |
|
✗ |
long double Stopwatch::get_average_time(const string& perf_name) { |
301 |
|
|
// Try to recover performance data |
302 |
|
✗ |
if (!performance_exists(perf_name)) |
303 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
304 |
|
|
|
305 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
306 |
|
|
|
307 |
|
✗ |
return (perf_info.total_time / (long double)perf_info.stops); |
308 |
|
|
} |
309 |
|
|
|
310 |
|
✗ |
long double Stopwatch::get_min_time(const string& perf_name) { |
311 |
|
|
// Try to recover performance data |
312 |
|
✗ |
if (!performance_exists(perf_name)) |
313 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
314 |
|
|
|
315 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
316 |
|
|
|
317 |
|
✗ |
return perf_info.min_time; |
318 |
|
|
} |
319 |
|
|
|
320 |
|
✗ |
long double Stopwatch::get_max_time(const string& perf_name) { |
321 |
|
|
// Try to recover performance data |
322 |
|
✗ |
if (!performance_exists(perf_name)) |
323 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
324 |
|
|
|
325 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
326 |
|
|
|
327 |
|
✗ |
return perf_info.max_time; |
328 |
|
|
} |
329 |
|
|
|
330 |
|
✗ |
long double Stopwatch::get_last_time(const string& perf_name) { |
331 |
|
|
// Try to recover performance data |
332 |
|
✗ |
if (!performance_exists(perf_name)) |
333 |
|
✗ |
throw StopwatchException("Performance not initialized."); |
334 |
|
|
|
335 |
|
✗ |
PerformanceData& perf_info = records_of->find(perf_name)->second; |
336 |
|
|
|
337 |
|
✗ |
return perf_info.last_time; |
338 |
|
|
} |
339 |
|
|
|
340 |
|
✗ |
Stopwatch::Watcher Stopwatch::watcher(const string& perf_name) { |
341 |
|
✗ |
if (!active) return Watcher(*this, perf_name, nullptr); |
342 |
|
|
|
343 |
|
✗ |
const auto it = records_of->insert(make_pair(perf_name, PerformanceData())); |
344 |
|
|
|
345 |
|
✗ |
PerformanceData* perf_info = &(it.first->second); |
346 |
|
|
|
347 |
|
✗ |
return Watcher(*this, perf_name, perf_info); |
348 |
|
|
} |
349 |
|
|
|
350 |
|
✗ |
void Stopwatch::Watcher::_start() { |
351 |
|
✗ |
if (!w.profiler_active) return; |
352 |
|
|
|
353 |
|
✗ |
if (p == nullptr) { |
354 |
|
✗ |
p = &w.get_or_create_perf(n); |
355 |
|
|
} |
356 |
|
|
|
357 |
|
✗ |
p->clock_start = w.take_time(); |
358 |
|
✗ |
p->paused = false; |
359 |
|
|
} |
360 |
|
|
|
361 |
|
✗ |
void Stopwatch::Watcher::_stop() { |
362 |
|
✗ |
if (!w.profiler_active || (p == nullptr)) return; |
363 |
|
|
|
364 |
|
✗ |
long double clock_end = w.take_time(); |
365 |
|
✗ |
w.stop_perf(*p, clock_end); |
366 |
|
|
} |
367 |
|
|
|
368 |
|
|
} // end namespace crocoddyl |
369 |
|
|
|