Main MRPT website > C++ reference for MRPT 1.9.9
CTimeLogger.cpp
Go to the documentation of this file.
1 /* +------------------------------------------------------------------------+
2  | Mobile Robot Programming Toolkit (MRPT) |
3  | http://www.mrpt.org/ |
4  | |
5  | Copyright (c) 2005-2018, Individual contributors, see AUTHORS file |
6  | See: http://www.mrpt.org/Authors - All rights reserved. |
7  | Released under BSD License. See details in http://www.mrpt.org/License |
8  +------------------------------------------------------------------------+ */
9 
10 #include "system-precomp.h" // Precompiled headers
11 
14 #include <mrpt/core/bits_math.h>
15 #include <iostream>
16 #include <fstream>
17 
18 using namespace mrpt;
19 using namespace mrpt::system;
20 using namespace std;
21 
23 {
24  MyGlobalProfiler() : mrpt::system::CTimeLogger("MRPT_global_profiler") {}
26  {
27  if (!m_data.empty())
28  {
29  const std::string sFil("mrpt-global-profiler.csv");
30  this->saveToCSVFile(sFil);
31  std::cout << "[MRPT global profiler] Write stats to: " << sFil
32  << std::endl;
33  }
34  }
35 };
37 
38 namespace mrpt
39 {
40 namespace system
41 {
43 void global_profiler_enter(const char* func_name) noexcept
44 {
45  global_profiler.enter(func_name);
46 }
47 void global_profiler_leave(const char* func_name) noexcept
48 {
49  global_profiler.leave(func_name);
50 }
51 }
52 }
53 
55  bool enabled /*=true*/, const std::string& name /*=""*/)
56  : COutputLogger("CTimeLogger"), m_tictac(), m_enabled(enabled), m_name(name)
57 {
58  m_tictac.Tic();
59 }
60 
62 {
63  // Dump all stats:
64  if (!m_data.empty()) // If logging is disabled, do nothing...
65  dumpAllStats();
66 }
67 
69  : COutputLogger(o),
70  m_enabled(o.m_enabled),
71  m_name(o.m_name),
72  m_data(o.m_data)
73 {
74 }
76 {
77  COutputLogger::operator=(o);
78  m_enabled = o.m_enabled;
79  m_name = o.m_name;
80  m_data = o.m_data;
81  return *this;
82 }
84  : COutputLogger(o),
85  m_enabled(o.m_enabled),
86  m_name(o.m_name),
87  m_data(o.m_data)
88 {
89 }
91 {
92  COutputLogger::operator=(o);
93  m_enabled = o.m_enabled;
94  m_name = o.m_name;
95  m_data = o.m_data;
96  return *this;
97 }
98 
99 void CTimeLogger::clear(bool deep_clear)
100 {
101  if (deep_clear)
102  m_data.clear();
103  else
104  {
105  for (auto& e : m_data) e.second = TCallData();
106  }
107 }
108 
110 {
111  std::string ret;
112 
113  for (size_t p = 0; p < s.size(); p += len)
114  {
115  ret += rightPad(s.c_str() + p, len, true);
116  if (p + len < s.size()) ret += "\n";
117  }
118  return ret;
119 }
120 
121 void CTimeLogger::getStats(std::map<std::string, TCallStats>& out_stats) const
122 {
123  out_stats.clear();
124  for (const auto e : m_data)
125  {
126  TCallStats& cs = out_stats[e.first];
127  cs.min_t = e.second.min_t;
128  cs.max_t = e.second.max_t;
129  cs.total_t = e.second.mean_t;
130  cs.mean_t = e.second.n_calls ? e.second.mean_t / e.second.n_calls : 0;
131  cs.n_calls = e.second.n_calls;
132  cs.last_t = e.second.last_t;
133  }
134 }
135 
136 std::string CTimeLogger::getStatsAsText(const size_t column_width) const
137 {
138  std::string stats_text;
139  std::string name_tmp = m_name.size() ? " " + m_name + ": " : " ";
140  std::string mrpt_string = "MRPT CTimeLogger report ";
141 
142  std::string top_header(name_tmp + mrpt_string);
143  // append dashes to the header to reach column_width
144  {
145  int space_to_fill = top_header.size() < column_width
146  ? (column_width - top_header.size()) / 2
147  : 2;
148  std::string dashes_half(space_to_fill, '-');
149  top_header = dashes_half + top_header + dashes_half;
150  if (dashes_half.size() % 2)
151  { // what if column_width-top_header.size() is odd?
152  top_header += '-';
153  }
154  }
155 
156  std::string middle_header(
157  " FUNCTION #CALLS MIN.T MEAN.T "
158  "MAX.T TOTAL ");
159  std::string bottom_header(column_width, '-');
160 
161  stats_text += top_header + "\n";
162  stats_text += middle_header + "\n";
163  stats_text += bottom_header + "\n";
164 
165  // for all the timed sections
166  for (const auto i : m_data)
167  {
168  const string sMinT = unitsFormat(i.second.min_t, 1, false);
169  const string sMaxT = unitsFormat(i.second.max_t, 1, false);
170  const string sTotalT = unitsFormat(i.second.mean_t, 1, false);
171  const string sMeanT = unitsFormat(
172  i.second.n_calls ? i.second.mean_t / i.second.n_calls : 0, 1,
173  false);
174 
175  stats_text += format(
176  "%s %7u %6s%c %6s%c %6s%c %6s%c\n",
177  aux_format_string_multilines(i.first, 39).c_str(),
178  static_cast<unsigned int>(i.second.n_calls), sMinT.c_str(),
179  i.second.has_time_units ? 's' : ' ', sMeanT.c_str(),
180  i.second.has_time_units ? 's' : ' ', sMaxT.c_str(),
181  i.second.has_time_units ? 's' : ' ', sTotalT.c_str(),
182  i.second.has_time_units ? 's' : ' ');
183  }
184 
185  std::string footer(top_header);
186  stats_text += footer + "\n";
187 
188  return stats_text;
189 }
190 
191 void CTimeLogger::saveToCSVFile(const std::string& csv_file) const
192 {
193  std::string s;
194  s += "FUNCTION, #CALLS, LAST.T, MIN.T, MEAN.T, MAX.T, TOTAL.T\n";
195  for (const auto& i : m_data)
196  {
197  s += format(
198  "\"%s\",\"%7u\",\"%e\",\"%e\",\"%e\",\"%e\",\"%e\"\n",
199  i.first.c_str(), static_cast<unsigned int>(i.second.n_calls),
200  i.second.last_t, i.second.min_t,
201  i.second.n_calls ? i.second.mean_t / i.second.n_calls : 0,
202  i.second.max_t, i.second.mean_t);
203  }
204  std::ofstream(csv_file) << s;
205 }
206 
207 void CTimeLogger::dumpAllStats(const size_t column_width) const
208 {
209  MRPT_LOG_INFO_STREAM("dumpAllStats:\n" << getStatsAsText(column_width));
210 }
211 
212 void CTimeLogger::do_enter(const char* func_name)
213 {
214  const string s = func_name;
215  TCallData& d = m_data[s];
216 
217  d.n_calls++;
218  d.open_calls.push(0); // Dummy value, it'll be written below
219  d.open_calls.top() = m_tictac.Tac(); // to avoid possible delays.
220 }
221 
222 double CTimeLogger::do_leave(const char* func_name)
223 {
224  const double tim = m_tictac.Tac();
225 
226  const string s = func_name;
227  TCallData& d = m_data[s];
228 
229  if (!d.open_calls.empty())
230  {
231  const double At = tim - d.open_calls.top();
232  d.open_calls.pop();
233 
234  d.last_t = At;
235  d.mean_t += At;
236  if (d.n_calls == 1)
237  {
238  d.min_t = At;
239  d.max_t = At;
240  }
241  else
242  {
243  mrpt::keep_min(d.min_t, At);
244  mrpt::keep_max(d.max_t, At);
245  }
246  return At;
247  }
248  else
249  return 0; // This shouldn't happen!
250 }
251 
253  const char* event_name, const double value)
254 {
255  if (!m_enabled) return;
256  const string s = event_name;
257  TCallData& d = m_data[s];
258 
259  d.has_time_units = false;
260  d.last_t = value;
261  d.mean_t += value;
262  if (++d.n_calls == 1)
263  {
264  d.min_t = value;
265  d.max_t = value;
266  }
267  else
268  {
271  }
272 }
273 
275  : n_calls(0), min_t(0), max_t(0), mean_t(0), last_t(0), has_time_units(true)
276 {
277 }
278 
280 {
282  if (it == m_data.end())
283  return 0;
284  else
285  return it->second.n_calls ? it->second.mean_t / it->second.n_calls : 0;
286 }
288 {
290  if (it == m_data.end())
291  return 0;
292  else
293  return it->second.last_t;
294 }
295 
297  const CTimeLogger& logger, const char* section_name)
298  : m_logger(const_cast<CTimeLogger&>(logger)), m_section_name(section_name)
299 {
301 }
double Tac() noexcept
Stops the stopwatch.
Definition: CTicTac.cpp:90
This namespace provides a OS-independent interface to many useful functions: filenames manipulation...
Definition: math_frwds.h:25
void clear(bool deep_clear=false)
Resets all stats.
Definition: CTimeLogger.cpp:99
CTimeLogger & m_logger
void do_enter(const char *func_name)
double do_leave(const char *func_name)
void dumpAllStats(const size_t column_width=80) const
Dump all stats through the COutputLogger interface.
STL namespace.
mrpt::system::CTimeLogger & global_profiler_getref() noexcept
Definition: CTimeLogger.cpp:42
void keep_min(T &var, const K test_val)
If the second argument is below the first one, set the first argument to this lower value...
double getLastTime(const std::string &name) const
Return the last execution time of the given "section", or 0 if it hasn&#39;t ever been called "enter" wit...
void getStats(std::map< std::string, TCallStats > &out_stats) const
Returns all the current stats as a map: section_name => stats.
GLdouble s
Definition: glext.h:3676
GLenum GLsizei len
Definition: glext.h:4712
std::string getStatsAsText(const size_t column_width=80) const
Dump all stats to a multi-line text string.
MyGlobalProfiler global_profiler
Definition: CTimeLogger.cpp:36
std::stack< double, std::vector< double > > open_calls
void global_profiler_enter(const char *func_name) noexcept
Definition: CTimeLogger.cpp:43
void keep_max(T &var, const K test_val)
If the second argument is above the first one, set the first argument to this higher value...
Versatile class for consistent logging and management of output messages.
virtual ~CTimeLogger()
Default constructor.
Definition: CTimeLogger.cpp:61
CTimeLoggerEntry(const CTimeLogger &logger, const char *section_name)
std::string format(const char *fmt,...) MRPT_printf_format_check(1
A std::string version of C sprintf.
Definition: format.cpp:16
double leave(const char *func_name)
End of a named section.
GLsizei const GLchar ** string
Definition: glext.h:4101
double getMeanTime(const std::string &name) const
Return the mean execution time of the given "section", or 0 if it hasn&#39;t ever been called "enter" wit...
#define MRPT_LOG_INFO_STREAM(__CONTENTS)
CTimeLogger & operator=(const CTimeLogger &o)
Definition: CTimeLogger.cpp:75
void global_profiler_leave(const char *func_name) noexcept
Definition: CTimeLogger.cpp:47
This is the global namespace for all Mobile Robot Programming Toolkit (MRPT) libraries.
std::string unitsFormat(const double val, int nDecimalDigits=2, bool middle_space=true)
This function implements formatting with the appropriate SI metric unit prefix: 1e-12->&#39;p&#39;, 1e-9->&#39;n&#39;, 1e-6->&#39;u&#39;, 1e-3->&#39;m&#39;, 1->&#39;&#39;, 1e3->&#39;K&#39;, 1e6->&#39;M&#39;, 1e9->&#39;G&#39;, 1e12->&#39;T&#39;.
A versatile "profiler" that logs the time spent within each pair of calls to enter(X)-leave(X), among other stats.
void saveToCSVFile(const std::string &csv_file) const
Dump all stats to a Comma Separated Values (CSV) file.
Data of each call section: # of calls, minimum, maximum, average and overall execution time (in secon...
std::string aux_format_string_multilines(const std::string &s, const size_t len)
GLuint const GLchar * name
Definition: glext.h:4054
~CTimeLoggerEntry()
std::string rightPad(const std::string &str, const size_t total_len, bool truncate_if_larger=false)
Enlarge the string with spaces up to the given length.
GLsizei const GLfloat * value
Definition: glext.h:4117
void Tic() noexcept
Starts the stopwatch.
Definition: CTicTac.cpp:79
GLfloat GLfloat p
Definition: glext.h:6305
const Scalar * const_iterator
Definition: eigen_plugins.h:27
const char * m_section_name
CTimeLogger(bool enabled=true, const std::string &name="")
Definition: CTimeLogger.cpp:54
void registerUserMeasure(const char *event_name, const double value)
void enter(const char *func_name)
Start of a named section.



Page generated by Doxygen 1.8.14 for MRPT 1.9.9 Git: ad3a9d8ae Tue May 1 23:10:22 2018 -0700 at lun oct 28 00:14:14 CET 2019