JeVois  1.5
JeVois Smart Embedded Machine Vision Toolkit
Share this page:
Profiler.C
Go to the documentation of this file.
1 // ///////////////////////////////////////////////////////////////////////////////////////////////////////////////////
2 //
3 // JeVois Smart Embedded Machine Vision Toolkit - Copyright (C) 2016 by Laurent Itti, the University of Southern
4 // California (USC), and iLab at USC. See http://iLab.usc.edu and http://jevois.org for information about this project.
5 //
6 // This file is part of the JeVois Smart Embedded Machine Vision Toolkit. This program is free software; you can
7 // redistribute it and/or modify it under the terms of the GNU General Public License as published by the Free Software
8 // Foundation, version 2. This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY;
9 // without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public
10 // License for more details. You should have received a copy of the GNU General Public License along with this program;
11 // if not, write to the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
12 //
13 // Contact information: Laurent Itti - 3641 Watt Way, HNB-07A - Los Angeles, CA 90089-2520 - USA.
14 // Tel: +1 213 740 3527 - itti@pollux.usc.edu - http://iLab.usc.edu - http://jevois.org
15 // ///////////////////////////////////////////////////////////////////////////////////////////////////////////////////
16 /*! \file */
17 
18 #include <jevois/Debug/Profiler.H>
19 #include <jevois/Debug/Log.H>
20 #include <sstream>
21 
22 namespace
23 {
24  void secs2str(std::ostringstream & ss, double secs)
25  {
26  if (secs < 1.0e-6) ss << secs * 1.0e9 << "ns";
27  else if (secs < 1.0e-3) ss << secs * 1.0e6 << "us";
28  else if (secs < 1.0) ss << secs * 1.0e3 << "ms";
29  else ss << secs << 's';
30  }
31 }
32 
33 // ####################################################################################################
34 jevois::Profiler::Profiler(char const * prefix, size_t interval, int loglevel) :
35  itsPrefix(prefix), itsInterval(interval), itsLogLevel(loglevel),
36  itsStartTime(std::chrono::high_resolution_clock::now())
37 {
38  itsData = { "", 0, 0.0, 1.0e30, -1.0e30, itsStartTime };
39  if (interval == 0) LFATAL("Interval must be > 0");
40 }
41 
42 // ####################################################################################################
44 {
45  itsStartTime = std::chrono::high_resolution_clock::now();
46 }
47 
48 // ####################################################################################################
49 void jevois::Profiler::checkpoint(char const * desc)
50 {
51  std::chrono::time_point<std::chrono::high_resolution_clock> now = std::chrono::high_resolution_clock::now();
52 
53  // See if we already have that desc:
54  size_t const sz = itsCheckpointData.size();
55  for (size_t i = 0; i < sz; ++i)
56  {
57  data & cpd = itsCheckpointData[i];
58  if (cpd.desc == desc)
59  {
60  // Not the first time we have this checkpoint, update the values in cpd:
61  std::chrono::duration<double> dur;
62  if (i == 0) dur = now - itsStartTime; else dur = now - itsCheckpointData[i - 1].lasttime;
63  double const secs = dur.count();
64 
65  ++cpd.count;
66  cpd.secs += secs;
67  if (secs < cpd.minsecs) cpd.minsecs = secs;
68  if (secs > cpd.maxsecs) cpd.maxsecs = secs;
69  cpd.lasttime = now;
70 
71  return;
72  }
73  }
74 
75  // First time this description is encountered, create new entry in itsCheckpointData
76  std::chrono::duration<double> dur;
77  if (sz == 0) dur = now - itsStartTime; else dur = now - itsCheckpointData[sz - 1].lasttime;
78  double secs = dur.count();
79 
80  itsCheckpointData.push_back({ desc, 1, secs, secs, secs, now });
81 }
82 
83 // ####################################################################################################
85 {
86  std::chrono::duration<double> const dur = std::chrono::high_resolution_clock::now() - itsStartTime;
87  double secs = dur.count();
88 
89  // Update average duration computation:
90  itsData.secs += secs; ++itsData.count;
91 
92  // Update min and max:
93  if (secs < itsData.minsecs) itsData.minsecs = secs;
94  if (secs > itsData.maxsecs) itsData.maxsecs = secs;
95 
96  if (itsData.count >= itsInterval)
97  {
98  // First the overall start-to-stop report, include fps:
99  double const avgsecs = itsData.secs / itsData.count;
100  std::ostringstream ss;
101  ss << itsPrefix << " overall average (" << itsData.count << ") duration "; secs2str(ss, avgsecs);
102  ss << " ["; secs2str(ss, itsData.minsecs); ss << " .. "; secs2str(ss, itsData.maxsecs); ss<< ']';
103 
104  if (avgsecs > 0.0) ss << " (" << 1.0 / avgsecs << " fps)";
105 
106  switch (itsLogLevel)
107  {
108  case LOG_INFO: LINFO(ss.str()); break;
109  case LOG_ERR: LERROR(ss.str()); break;
110  case LOG_CRIT: LFATAL(ss.str()); break;
111  default: LDEBUG(ss.str());
112  }
113 
114  // Now same thing but for each checkpoint entry:
115  for (data const & cpd : itsCheckpointData)
116  {
117  double const cpavgsecs = cpd.count ? cpd.secs / cpd.count : 0.0;
118  std::ostringstream cpss;
119  cpss << itsPrefix << " - " << cpd.desc << " average (" << cpd.count << ") delta duration ";
120  secs2str(cpss, cpavgsecs); cpss << " ["; secs2str(cpss, cpd.minsecs); cpss << " .. ";
121  secs2str(cpss, cpd.maxsecs); cpss<< ']';
122 
123  if (cpavgsecs > 0.0) cpss << " (" << 1.0 / cpavgsecs << " fps)";
124 
125  switch (itsLogLevel)
126  {
127  case LOG_INFO: LINFO(cpss.str()); break;
128  case LOG_ERR: LERROR(cpss.str()); break;
129  case LOG_CRIT: LFATAL(cpss.str()); break;
130  default: LDEBUG(cpss.str());
131  }
132  }
133 
134  // Get ready for the next cycle:
135  itsData = { "", 0, 0.0, 1.0e30, -1.0e30, itsStartTime };
136  itsCheckpointData.clear();
137  }
138 }
139 
#define LDEBUG(msg)
Convenience macro for users to print out console or syslog messages, DEBUG level. ...
Definition: Log.H:155
STL namespace.
Profiler(char const *prefix, size_t interval=100, int loglevel=LOG_INFO)
Constructor.
Definition: Profiler.C:34
void checkpoint(char const *description)
Note the time for a particular event.
Definition: Profiler.C:49
#define LERROR(msg)
Convenience macro for users to print out console or syslog messages, ERROR level. ...
Definition: Log.H:193
void start()
Start a time measurement period.
Definition: Profiler.C:43
#define LFATAL(msg)
Convenience macro for users to print out console or syslog messages, FATAL level. ...
Definition: Log.H:212
void stop()
End a time measurement period, report time spent for each checkpoint if reporting interval is reached...
Definition: Profiler.C:84
#define LINFO(msg)
Convenience macro for users to print out console or syslog messages, INFO level.
Definition: Log.H:176