JeVois  1.20
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 <jevois/Util/Utils.H>
21 #include <sstream>
22 
23 // ####################################################################################################
24 jevois::Profiler::Profiler(char const * prefix, size_t interval, int loglevel) :
25  itsPrefix(prefix), itsInterval(interval), itsLogLevel(loglevel),
26  itsStartTime(std::chrono::steady_clock::now())
27 {
28  itsData = { "", 0, 0.0, 1.0e30, -1.0e30, itsStartTime };
29  if (interval == 0) LFATAL("Interval must be > 0");
30 }
31 
32 // ####################################################################################################
34 {
35  itsStartTime = std::chrono::steady_clock::now();
36 }
37 
38 // ####################################################################################################
39 void jevois::Profiler::checkpoint(char const * desc)
40 {
41  std::chrono::time_point<std::chrono::steady_clock> now = std::chrono::steady_clock::now();
42 
43  // See if we already have that desc:
44  size_t const sz = itsCheckpointData.size();
45  for (size_t i = 0; i < sz; ++i)
46  {
47  data & cpd = itsCheckpointData[i];
48  if (cpd.desc == desc)
49  {
50  // Not the first time we have this checkpoint, update the values in cpd:
51  std::chrono::duration<double> dur;
52  if (i == 0) dur = now - itsStartTime; else dur = now - itsCheckpointData[i - 1].lasttime;
53  double const secs = dur.count();
54 
55  ++cpd.count;
56  cpd.secs += secs;
57  if (secs < cpd.minsecs) cpd.minsecs = secs;
58  if (secs > cpd.maxsecs) cpd.maxsecs = secs;
59  cpd.lasttime = now;
60 
61  return;
62  }
63  }
64 
65  // First time this description is encountered, create new entry in itsCheckpointData
66  std::chrono::duration<double> dur;
67  if (sz == 0) dur = now - itsStartTime; else dur = now - itsCheckpointData[sz - 1].lasttime;
68  double secs = dur.count();
69 
70  itsCheckpointData.push_back({ desc, 1, secs, secs, secs, now });
71 }
72 
73 // ####################################################################################################
75 {
76  std::chrono::duration<double> const dur = std::chrono::steady_clock::now() - itsStartTime;
77  double secs = dur.count();
78 
79  // Update average duration computation:
80  itsData.secs += secs; ++itsData.count;
81 
82  // Update min and max:
83  if (secs < itsData.minsecs) itsData.minsecs = secs;
84  if (secs > itsData.maxsecs) itsData.maxsecs = secs;
85 
86  if (itsData.count >= itsInterval)
87  {
88  // First the overall start-to-stop report, include fps:
89  double const avgsecs = itsData.secs / itsData.count;
90  std::ostringstream ss;
91  ss << itsPrefix << " overall average (" << itsData.count << ") duration "; jevois::secs2str(ss, avgsecs);
92  ss << " ["; jevois::secs2str(ss, itsData.minsecs); ss << " .. "; jevois::secs2str(ss, itsData.maxsecs); ss<< ']';
93 
94  if (avgsecs > 0.0) ss << " (" << 1.0 / avgsecs << " fps)";
95 
96  switch (itsLogLevel)
97  {
98  case LOG_INFO: LINFO(ss.str()); break;
99  case LOG_ERR: LERROR(ss.str()); break;
100  case LOG_CRIT: LFATAL(ss.str()); break;
101  default: LDEBUG(ss.str());
102  }
103 
104  // Now same thing but for each checkpoint entry:
105  for (data const & cpd : itsCheckpointData)
106  {
107  double const cpavgsecs = cpd.count ? cpd.secs / cpd.count : 0.0;
108  std::ostringstream cpss;
109  cpss << itsPrefix << " - " << cpd.desc << " average (" << cpd.count << ") delta duration ";
110  jevois::secs2str(cpss, cpavgsecs); cpss << " ["; jevois::secs2str(cpss, cpd.minsecs); cpss << " .. ";
111  jevois::secs2str(cpss, cpd.maxsecs); cpss<< ']';
112 
113  if (cpavgsecs > 0.0) cpss << " (" << 1.0 / cpavgsecs << " fps)";
114 
115  switch (itsLogLevel)
116  {
117  case LOG_INFO: LINFO(cpss.str()); break;
118  case LOG_ERR: LERROR(cpss.str()); break;
119  case LOG_CRIT: LFATAL(cpss.str()); break;
120  default: LDEBUG(cpss.str());
121  }
122  }
123 
124  // Get ready for the next cycle:
125  itsData = { "", 0, 0.0, 1.0e30, -1.0e30, itsStartTime };
126  itsCheckpointData.clear();
127  }
128 }
129 
LDEBUG
#define LDEBUG(msg)
Convenience macro for users to print out console or syslog messages, DEBUG level.
Definition: Log.H:173
jevois::Profiler::checkpoint
void checkpoint(char const *description)
Note the time for a particular event.
Definition: Profiler.C:39
LERROR
#define LERROR(msg)
Convenience macro for users to print out console or syslog messages, ERROR level.
Definition: Log.H:211
Log.H
Profiler.H
LFATAL
#define LFATAL(msg)
Convenience macro for users to print out console or syslog messages, FATAL level.
jevois::secs2str
std::string secs2str(double secs)
Report a duration given in seconds with variable units (ns, us, ms, or s), with precision of 2 decima...
Definition: Utils.C:478
jevois::Profiler::start
void start()
Start a time measurement period.
Definition: Profiler.C:33
Utils.H
jevois::Profiler::stop
void stop()
End a time measurement period, report time spent for each checkpoint if reporting interval is reached...
Definition: Profiler.C:74
jevois::Profiler::Profiler
Profiler(char const *prefix, size_t interval=100, int loglevel=LOG_INFO)
Constructor.
Definition: Profiler.C:24
LINFO
#define LINFO(msg)
Convenience macro for users to print out console or syslog messages, INFO level.
Definition: Log.H:194