Main MRPT website > C++ reference for MRPT 1.5.6
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-2017, 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 "base-precomp.h" // Precompiled headers
11 
12 #include <mrpt/utils/CTimeLogger.h>
15 
16 #include <iostream>
17 
18 using namespace mrpt;
19 using namespace mrpt::utils;
20 using namespace mrpt::system;
21 using namespace std;
22 
24 {
25  MyGlobalProfiler() : mrpt::utils::CTimeLogger("MRPT_global_profiler")
26  {}
27 
29  {
30  if (!m_data.empty())
31  {
32  const std::string sFil("mrpt-global-profiler.csv");
33  this->saveToCSVFile(sFil);
34  std::cout << "[MRPT global profiler] Write stats to: "<< sFil <<std::endl;
35  }
36  }
37 };
39 
40 namespace mrpt
41 {
42  namespace utils
43  {
45  return global_profiler;
46  }
47 
48  void global_profiler_enter(const char *func_name) MRPT_NO_THROWS {
49  global_profiler.enter(func_name);
50  }
51  void global_profiler_leave(const char *func_name) MRPT_NO_THROWS {
52  global_profiler.leave(func_name);
53  }
54  }
55 }
56 
57 CTimeLogger::CTimeLogger(bool enabled/*=true*/, const std::string& name/*=""*/) :
58  COutputLogger("CTimeLogger"),
59  m_tictac(),
60  m_enabled(enabled),
61  m_name(name)
62 {
63  m_tictac.Tic();
64 }
65 
67 {
68  // Dump all stats:
69  if (!m_data.empty()) // If logging is disabled, do nothing...
70  dumpAllStats();
71 }
72 
74  COutputLogger(o),
75  m_enabled(o.m_enabled),
76  m_name(o.m_name),
77  m_data(o.m_data)
78 {
79 }
81 {
82  COutputLogger::operator=(o);
83  m_enabled = o.m_enabled;
84  m_name = o.m_name;
85  m_data = o.m_data;
86  return *this;
87 }
88 #if MRPT_HAS_CXX11
90  COutputLogger(o),
91  m_enabled(o.m_enabled),
92  m_name(o.m_name),
93  m_data(o.m_data)
94 {
95 }
97 {
98  COutputLogger::operator=(o);
99  m_enabled = o.m_enabled;
100  m_name = o.m_name;
101  m_data = o.m_data;
102  return *this;
103 }
104 #endif
105 
106 
107 void CTimeLogger::clear(bool deep_clear)
108 {
109  if (deep_clear)
110  m_data.clear();
111  else
112  {
113  for (auto &e : m_data)
114  e.second = TCallData();
115  }
116 }
117 
119 {
120  std::string ret;
121 
122  for (size_t p=0;p<s.size();p+=len)
123  {
124  ret+=rightPad(s.c_str()+p,len,true);
125  if (p+len<s.size())
126  ret+="\n";
127  }
128  return ret;
129 }
130 
131 void CTimeLogger::getStats(std::map<std::string,TCallStats> &out_stats) const
132 {
133  out_stats.clear();
134  for (const auto e : m_data)
135  {
136  TCallStats &cs = out_stats[e.first];
137  cs.min_t = e.second.min_t;
138  cs.max_t = e.second.max_t;
139  cs.total_t = e.second.mean_t;
140  cs.mean_t = e.second.n_calls ? e.second.mean_t/ e.second.n_calls : 0;
141  cs.n_calls = e.second.n_calls;
142  cs.last_t = e.second.last_t;
143  }
144 }
145 
146 std::string CTimeLogger::getStatsAsText(const size_t column_width) const
147 {
148  std::string stats_text;
149  std::string name_tmp = m_name.size() ? " " + m_name + ": " : " ";
150  std::string mrpt_string = "MRPT CTimeLogger report ";
151 
152  std::string top_header(name_tmp + mrpt_string);
153  // append dashes to the header to reach column_width
154  {
155  int space_to_fill = top_header.size() < column_width?
156  (column_width-top_header.size())/2 : 2;
157  std::string dashes_half(space_to_fill, '-');
158  top_header = dashes_half + top_header + dashes_half;
159  if (dashes_half.size() % 2) { // what if column_width-top_header.size() is odd?
160  top_header += '-';
161  }
162  }
163 
164  std::string middle_header(" FUNCTION #CALLS MIN.T MEAN.T MAX.T TOTAL ");
165  std::string bottom_header(column_width, '-');
166 
167  stats_text += top_header + "\n";
168  stats_text += middle_header + "\n";
169  stats_text += bottom_header + "\n";
170 
171  // for all the timed sections
172  for (const auto i : m_data)
173  {
174  const string sMinT = unitsFormat(i.second.min_t,1,false);
175  const string sMaxT = unitsFormat(i.second.max_t,1,false);
176  const string sTotalT = unitsFormat(i.second.mean_t,1,false);
177  const string sMeanT = unitsFormat(i.second.n_calls ? i.second.mean_t/i.second.n_calls : 0,1,false);
178 
179  stats_text+=format("%s %7u %6s%c %6s%c %6s%c %6s%c\n",
180  aux_format_string_multilines(i.first,39).c_str(),
181  static_cast<unsigned int>(i.second.n_calls),
182  sMinT.c_str(), i.second.has_time_units ? 's':' ',
183  sMeanT.c_str(),i.second.has_time_units ? 's':' ',
184  sMaxT.c_str(),i.second.has_time_units ? 's':' ',
185  sTotalT.c_str(),i.second.has_time_units ? 's':' ' );
186  }
187 
188  std::string footer(top_header);
189  stats_text += footer + "\n";
190 
191  return stats_text;
192 }
193 
194 void CTimeLogger::saveToCSVFile(const std::string &csv_file) const
195 {
196  std::string s;
197  s+="FUNCTION, #CALLS, LAST.T, MIN.T, MEAN.T, MAX.T, TOTAL.T\n";
198  for (const auto &i : m_data)
199  {
200  s+=format("\"%s\",\"%7u\",\"%e\",\"%e\",\"%e\",\"%e\",\"%e\"\n",
201  i.first.c_str(),
202  static_cast<unsigned int>(i.second.n_calls),
203  i.second.last_t,
204  i.second.min_t,
205  i.second.n_calls ? i.second.mean_t/i.second.n_calls : 0,
206  i.second.max_t,
207  i.second.mean_t );
208  }
209  CFileOutputStream(csv_file).printf("%s",s.c_str() );
210 }
211 
212 void CTimeLogger::dumpAllStats(const size_t column_width) const
213 {
214  MRPT_LOG_INFO_STREAM("dumpAllStats:\n" << getStatsAsText(column_width));
215 }
216 
217 void CTimeLogger::do_enter(const char *func_name)
218 {
219  const string s = func_name;
220  TCallData &d = m_data[s];
221 
222  d.n_calls++;
223  d.open_calls.push(0); // Dummy value, it'll be written below
224  d.open_calls.top() = m_tictac.Tac(); // to avoid possible delays.
225 }
226 
227 double CTimeLogger::do_leave(const char *func_name)
228 {
229  const double tim = m_tictac.Tac();
230 
231  const string s = func_name;
232  TCallData &d = m_data[s];
233 
234  if (!d.open_calls.empty())
235  {
236  const double At = tim - d.open_calls.top();
237  d.open_calls.pop();
238 
239  d.last_t = At;
240  d.mean_t+=At;
241  if (d.n_calls==1)
242  {
243  d.min_t= At;
244  d.max_t= At;
245  }
246  else
247  {
250  }
251  return At;
252  }
253  else return 0; // This shouldn't happen!
254 }
255 
256 void CTimeLogger::registerUserMeasure(const char *event_name, const double value)
257 {
258  if (!m_enabled) return;
259  const string s = event_name;
260  TCallData &d = m_data[s];
261 
262  d.has_time_units = false;
263  d.last_t = value;
264  d.mean_t+=value;
265  if (++d.n_calls==1)
266  {
267  d.min_t= value;
268  d.max_t= value;
269  }
270  else
271  {
272  mrpt::utils::keep_min( d.min_t, value);
273  mrpt::utils::keep_max( d.max_t, value);
274  }
275 }
276 
278  n_calls (0),
279  min_t (0),
280  max_t (0),
281  mean_t (0),
282  last_t (0),
283  has_time_units(true)
284 {
285 }
286 
288 {
289  TDataMap::const_iterator it = m_data.find(name);
290  if (it==m_data.end())
291  return 0;
292  else return it->second.n_calls ? it->second.mean_t/it->second.n_calls : 0;
293 }
295 {
296  TDataMap::const_iterator it = m_data.find(name);
297  if (it == m_data.end())
298  return 0;
299  else return it->second.last_t;
300 }
301 
302 CTimeLoggerEntry::CTimeLoggerEntry(const CTimeLogger &logger, const char*section_name ) : m_logger(const_cast<CTimeLogger &>(logger)),m_section_name(section_name)
303 {
305 }
307 {
309 }
#define MRPT_NO_THROWS
C++11 noexcept: Used after member declarations.
void saveToCSVFile(const std::string &csv_file) const
Dump all stats to a Comma Separated Values (CSV) file.
const Scalar * const_iterator
Definition: eigen_plugins.h:24
void Tic()
Starts the stopwatch.
Definition: CTicTac.cpp:77
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...
void getStats(std::map< std::string, TCallStats > &out_stats) const
Returns all the current stats as a map: section_name => stats.
MyGlobalProfiler global_profiler
Definition: CTimeLogger.cpp:38
GLsizei const GLfloat * value
Definition: glew.h:1756
mrpt::utils::CTimeLogger BASE_IMPEXP & global_profiler_getref() MRPT_NO_THROWS
Definition: CTimeLogger.cpp:44
void clear(bool deep_clear=false)
Resets all stats. By default (deep_clear=false), all section names are remembered (not freed) so the ...
GLdouble s
Definition: glew.h:1295
CTimeLogger & operator=(const CTimeLogger &o)
Definition: CTimeLogger.cpp:80
This CStream derived class allow using a file as a write-only, binary stream.
Data of all the calls:
Definition: CTimeLogger.h:49
CTimeLogger(bool enabled=true, const std::string &name="")
Definition: CTimeLogger.cpp:57
void dumpAllStats(const size_t column_width=80) const
Dump all stats through the COutputLogger interface.
GLenum GLsizei len
Definition: glew.h:3955
double do_leave(const char *func_name)
std::string BASE_IMPEXP format(const char *fmt,...) MRPT_printf_format_check(1
A std::string version of C sprintf.
Definition: format.cpp:21
void do_enter(const char *func_name)
Data of each call section: # of calls, minimum, maximum, average and overall execution time (in secon...
Definition: CTimeLogger.h:67
GLuint const GLchar * name
Definition: glew.h:1721
GLfloat GLfloat p
Definition: glew.h:10113
double getLastTime(const std::string &name) const
Return the last execution time of the given "section", or 0 if it hasn't ever been called "enter" w...
virtual ~CTimeLogger()
Default constructor.
Definition: CTimeLogger.cpp:66
double getMeanTime(const std::string &name) const
Return the mean execution time of the given "section", or 0 if it hasn't ever been called "enter" w...
CTimeLoggerEntry(const CTimeLogger &logger, const char *section_name)
#define MRPT_LOG_INFO_STREAM(__CONTENTS)
GLsizei const GLcharARB ** string
Definition: glew.h:3293
std::stack< double, std::vector< double > > open_calls
Definition: CTimeLogger.h:55
~CTimeLoggerEntry()
std::string BASE_IMPEXP unitsFormat(const double val, int nDecimalDigits=2, bool middle_space=true)
This function implements formatting with the appropriate SI metric unit prefix: 1e-12->'p', 1e-9->'n', 1e-6->'u', 1e-3->'m', 1->'', 1e3->'K', 1e6->'M', 1e9->'G', 1e12->'T'.
std::string aux_format_string_multilines(const std::string &s, const size_t len)
void BASE_IMPEXP global_profiler_enter(const char *func_name) MRPT_NO_THROWS
Definition: CTimeLogger.cpp:48
double Tac()
Stops the stopwatch.
Definition: CTicTac.cpp:92
A versatile "profiler" that logs the time spent within each pair of calls to enter(X)-leave(X), among other stats.
Definition: CTimeLogger.h:41
double leave(const char *func_name)
End of a named section.
Definition: CTimeLogger.h:102
const char * m_section_name
Definition: CTimeLogger.h:132
std::string getStatsAsText(const size_t column_width=80) const
Dump all stats to a multi-line text string.
void BASE_IMPEXP global_profiler_leave(const char *func_name) MRPT_NO_THROWS
Definition: CTimeLogger.cpp:51
std::string BASE_IMPEXP 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.
void registerUserMeasure(const char *event_name, const double value)
CTimeLogger & m_logger
Definition: CTimeLogger.h:131
void enter(const char *func_name)
Start of a named section.
Definition: CTimeLogger.h:97
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...
virtual int printf(const char *fmt,...) MRPT_printf_format_check(2
Writes a string to the stream in a textual form.
Definition: CStream.cpp:507



Page generated by Doxygen 1.8.6 for MRPT 1.5.6 Git: 4c65e84 Tue Apr 24 08:18:17 2018 +0200 at mar abr 24 08:26:17 CEST 2018