gtsam  4.1.0
gtsam
timing.h
Go to the documentation of this file.
1 /* ----------------------------------------------------------------------------
2 
3  * GTSAM Copyright 2010, Georgia Tech Research Corporation,
4  * Atlanta, Georgia 30332-0415
5  * All Rights Reserved
6  * Authors: Frank Dellaert, et al. (see THANKS for the full author list)
7 
8  * See LICENSE for the license information
9 
10  * -------------------------------------------------------------------------- */
11 
18 #pragma once
19 
20 #include <gtsam/base/FastMap.h>
21 #include <gtsam/dllexport.h>
22 #include <gtsam/config.h> // for GTSAM_USE_TBB
23 
24 #include <boost/smart_ptr/shared_ptr.hpp>
25 #include <boost/smart_ptr/weak_ptr.hpp>
26 #include <boost/version.hpp>
27 
28 #include <cstddef>
29 #include <string>
30 
31 // This file contains the GTSAM timing instrumentation library, a low-overhead method for
32 // learning at a medium-fine level how much time various components of an algorithm take
33 // in CPU and wall time.
34 //
35 // The output of this instrumentation is a call-tree-like printout containing statistics
36 // about each instrumented code block. To print this output at any time, call
37 // tictoc_print() or tictoc_print_().
38 //
39 // An overall point to be aware of is that there are two versions of each function - one
40 // ending in an underscore '_' and one without the trailing underscore. The underscore
41 // versions always are active, but the versions without an underscore are active only when
42 // GTSAM_ENABLE_TIMING is defined (automatically defined in our CMake Timing build type).
43 // GTSAM algorithms are all instrumented with the non-underscore versions, so generally
44 // you should use the underscore versions in your own code to leave out the GTSAM detail.
45 //
46 // gttic and gttoc start and stop a timed section, respectively. gttic creates a *scoped*
47 // object - when it goes out of scope gttoc is called automatically. Thus, you do not
48 // need to call gttoc if you are timing an entire function (see basic use examples below).
49 // However, you must be *aware* of this scoped nature - putting gttic inside of an if(...)
50 // block, for example, will only time code until the closing brace '}'. See advanced
51 // usage below if you need to avoid this.
52 //
53 // Multiple calls nest automatically - each gttic nests under the previous gttic called
54 // for which gttoc has not been called (or the previous gttic did not go out of scope).
55 //
56 // Basic usage examples are as follows:
57 //
58 // - Timing an entire function:
59 // void myFunction() {
60 // gttic_(myFunction);
61 // ........
62 // }
63 //
64 // - Timing an entire function as well as its component parts:
65 // void myLongFunction() {
66 // gttic_(myLongFunction);
67 // gttic_(step1); // Will nest under the 'myLongFunction' label
68 // ........
69 // gttoc_(step1);
70 // gttic_(step2); // Will nest under the 'myLongFunction' label
71 // ........
72 // gttoc_(step2);
73 // ........
74 // }
75 //
76 // - Timing functions calling/called by other functions:
77 // void oneStep() {
78 // gttic_(oneStep); // Will automatically nest under the gttic label of the calling function
79 // .......
80 // }
81 // void algorithm() {
82 // gttic_(algorithm);
83 // oneStep(); // gttic's inside this function will automatically nest inside our 'algorithm' label
84 // twoStep(); // gttic's inside this function will automatically nest inside our 'algorithm' label
85 // }
86 //
87 //
88 // Advanced usage:
89 //
90 // - "Finishing iterations" - to get correct min/max times for each call, you must define
91 // in your code what constitutes an iteration. A single sum for the min/max times is
92 // accumulated within each iteration. If you don't care about min/max times, you don't
93 // need to worry about this. For example:
94 // void myOuterLoop() {
95 // while(true) {
96 // iterateMyAlgorithm();
97 // tictoc_finishedIteration_();
98 // tictoc_print_(); // Optional
99 // }
100 // }
101 //
102 // - Stopping timing a section in a different scope than it is started. Normally, a gttoc
103 // statement goes out of scope at end of C++ scope. However, you can use longtic and
104 // longtoc to start and stop timing with the specified label at any point, without regard
105 // too scope. Note that if you use these, it may become difficult to ensure that you
106 // have matching gttic/gttoc statments. You may want to consider reorganizing your timing
107 // outline to match the scope of your code.
108 
109 // Automatically use the new Boost timers if version is recent enough.
110 #if BOOST_VERSION >= 104800
111 # ifndef GTSAM_DISABLE_NEW_TIMERS
112 # define GTSAM_USING_NEW_BOOST_TIMERS
113 # endif
114 #endif
115 
116 #ifdef GTSAM_USING_NEW_BOOST_TIMERS
117 # include <boost/timer/timer.hpp>
118 #else
119 # include <boost/timer.hpp>
120 # include <gtsam/base/types.h>
121 #endif
122 
123 #ifdef GTSAM_USE_TBB
124 # include <tbb/tick_count.h>
125 # undef min
126 # undef max
127 # undef ERROR
128 #endif
129 
130 namespace gtsam {
131 
132  namespace internal {
133  // Generate/retrieve a unique global ID number that will be used to look up tic/toc statements
134  GTSAM_EXPORT size_t getTicTocID(const char *description);
135 
136  // Create new TimingOutline child for gCurrentTimer, make it gCurrentTimer, and call tic method
137  GTSAM_EXPORT void tic(size_t id, const char *label);
138 
139  // Call toc on gCurrentTimer and then set gCurrentTimer to the parent of gCurrentTimer
140  GTSAM_EXPORT void toc(size_t id, const char *label);
141 
146  protected:
147  size_t id_;
148  size_t t_;
149  size_t tWall_;
150  double t2_ ;
151  size_t tIt_;
152  size_t tMax_;
153  size_t tMin_;
154  size_t n_;
155  size_t myOrder_;
156  size_t lastChildOrder_;
157  std::string label_;
158 
159  // Tree structure
160  boost::weak_ptr<TimingOutline> parent_;
163 
164 #ifdef GTSAM_USING_NEW_BOOST_TIMERS
165  boost::timer::cpu_timer timer_;
166 #else
167  boost::timer timer_;
169 #endif
170 #ifdef GTSAM_USE_TBB
171  tbb::tick_count tbbTimer_;
172 #endif
173  void add(size_t usecs, size_t usecsWall);
174 
175  public:
177  GTSAM_EXPORT TimingOutline(const std::string& label, size_t myId);
178  GTSAM_EXPORT size_t time() const;
179  double secs() const { return double(time()) / 1000000.0;}
180  double self() const { return double(t_) / 1000000.0;}
181  double wall() const { return double(tWall_) / 1000000.0;}
182  double min() const { return double(tMin_) / 1000000.0;}
183  double max() const { return double(tMax_) / 1000000.0;}
184  double mean() const { return self() / double(n_); }
185  GTSAM_EXPORT void print(const std::string& outline = "") const;
186  GTSAM_EXPORT void print2(const std::string& outline = "", const double parentTotal = -1.0) const;
187  GTSAM_EXPORT const boost::shared_ptr<TimingOutline>&
188  child(size_t child, const std::string& label, const boost::weak_ptr<TimingOutline>& thisPtr);
189  GTSAM_EXPORT void tic();
190  GTSAM_EXPORT void toc();
191  GTSAM_EXPORT void finishedIteration();
192 
193  GTSAM_EXPORT friend void toc(size_t id, const char *label);
194  }; // \TimingOutline
195 
199  class GTSAM_EXPORT AutoTicToc {
200  private:
201  size_t id_;
202  const char* label_;
203  bool isSet_;
204 
205  public:
206  AutoTicToc(size_t id, const char* label)
207  : id_(id), label_(label), isSet_(true) {
208  tic(id_, label_);
209  }
210  void stop() {
211  toc(id_, label_);
212  isSet_ = false;
213  }
214  ~AutoTicToc() {
215  if (isSet_) stop();
216  }
217  };
218 
219  GTSAM_EXTERN_EXPORT boost::shared_ptr<TimingOutline> gTimingRoot;
220  GTSAM_EXTERN_EXPORT boost::weak_ptr<TimingOutline> gCurrentTimer;
221  }
222 
223 // Tic and toc functions that are always active (whether or not ENABLE_TIMING is defined)
224 // There is a trick being used here to achieve near-zero runtime overhead, in that a
225 // static variable is created for each tic/toc statement storing an integer ID, but the
226 // integer ID is only looked up by string once when the static variable is initialized
227 // as the program starts.
228 
229 // tic
230 #define gttic_(label) \
231  static const size_t label##_id_tic = ::gtsam::internal::getTicTocID(#label); \
232  ::gtsam::internal::AutoTicToc label##_obj(label##_id_tic, #label)
233 
234 // toc
235 #define gttoc_(label) \
236  label##_obj.stop()
237 
238 // tic
239 #define longtic_(label) \
240  static const size_t label##_id_tic = ::gtsam::internal::getTicTocID(#label); \
241  ::gtsam::internal::ticInternal(label##_id_tic, #label)
242 
243 // toc
244 #define longtoc_(label) \
245  static const size_t label##_id_toc = ::gtsam::internal::getTicTocID(#label); \
246  ::gtsam::internal::tocInternal(label##_id_toc, #label)
247 
248 // indicate iteration is finished
249 inline void tictoc_finishedIteration_() {
250  ::gtsam::internal::gTimingRoot->finishedIteration(); }
251 
252 // print
253 inline void tictoc_print_() {
254  ::gtsam::internal::gTimingRoot->print(); }
255 
256 // print mean and standard deviation
257 inline void tictoc_print2_() {
258  ::gtsam::internal::gTimingRoot->print2(); }
259 
260 // get a node by label and assign it to variable
261 #define tictoc_getNode(variable, label) \
262  static const size_t label##_id_getnode = ::gtsam::internal::getTicTocID(#label); \
263  const boost::shared_ptr<const ::gtsam::internal::TimingOutline> variable = \
264  ::gtsam::internal::gCurrentTimer.lock()->child(label##_id_getnode, #label, ::gtsam::internal::gCurrentTimer);
265 
266 // reset
267 inline void tictoc_reset_() {
268  ::gtsam::internal::gTimingRoot.reset(new ::gtsam::internal::TimingOutline("Total", ::gtsam::internal::getTicTocID("Total")));
269  ::gtsam::internal::gCurrentTimer = ::gtsam::internal::gTimingRoot; }
270 
271 #ifdef ENABLE_TIMING
272 #define gttic(label) gttic_(label)
273 #define gttoc(label) gttoc_(label)
274 #define longtic(label) longtic_(label)
275 #define longtoc(label) longtoc_(label)
276 #define tictoc_finishedIteration tictoc_finishedIteration_
277 #define tictoc_print tictoc_print_
278 #define tictoc_reset tictoc_reset_
279 #else
280 #define gttic(label) ((void)0)
281 #define gttoc(label) ((void)0)
282 #define longtic(label) ((void)0)
283 #define longtoc(label) ((void)0)
284 #define tictoc_finishedIteration() ((void)0)
285 #define tictoc_print() ((void)0)
286 #define tictoc_reset() ((void)0)
287 #endif
288 
289 }
gtsam::internal::TimingOutline::TimingOutline
GTSAM_EXPORT TimingOutline(const std::string &label, size_t myId)
Constructor.
Definition: timing.cpp:56
gtsam::internal::TimingOutline::t2_
double t2_
cache the \sum t_i^2
Definition: timing.h:150
gtsam::internal::TimingOutline::time
GTSAM_EXPORT size_t time() const
time taken, including children
Definition: timing.cpp:65
gtsam::ValueWithDefault< bool, false >
gtsam::internal::TimingOutline::min
double min() const
min time, in seconds
Definition: timing.h:182
gtsam::internal::TimingOutline::max
double max() const
max time, in seconds
Definition: timing.h:183
FastMap.h
A thin wrapper around std::map that uses boost's fast_pool_allocator.
types.h
Typedefs for easier changing of types.
gtsam::internal::TimingOutline::secs
double secs() const
time taken, in seconds, including children
Definition: timing.h:179
gtsam
Global functions in a separate testing namespace.
Definition: chartTesting.h:28
gtsam::internal::TimingOutline::parent_
boost::weak_ptr< TimingOutline > parent_
parent pointer
Definition: timing.h:160
gtsam::internal::TimingOutline::mean
double mean() const
mean self time, in seconds
Definition: timing.h:184
gtsam::internal::AutoTicToc
Small class that calls internal::tic at construction, and internol::toc when destroyed.
Definition: timing.h:199
gtsam::FastMap
Definition: FastMap.h:38
gtsam::internal::TimingOutline
Timing Entry, arranged in a tree.
Definition: timing.h:145
gtsam::internal::TimingOutline::children_
ChildMap children_
subtrees
Definition: timing.h:162
gtsam::internal::TimingOutline::wall
double wall() const
wall time, in seconds
Definition: timing.h:181