OR-Tools  9.6
stats.h
Go to the documentation of this file.
1 // Copyright 2010-2022 Google LLC
2 // Licensed under the Apache License, Version 2.0 (the "License");
3 // you may not use this file except in compliance with the License.
4 // You may obtain a copy of the License at
5 //
6 // http://www.apache.org/licenses/LICENSE-2.0
7 //
8 // Unless required by applicable law or agreed to in writing, software
9 // distributed under the License is distributed on an "AS IS" BASIS,
10 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
11 // See the License for the specific language governing permissions and
12 // limitations under the License.
13 
14 // Helper classes to track statistics of a program component.
15 //
16 // Usage example:
17 // // Suppose you have a class that contains a factorization of a matrix B and
18 // // a Solve() function to solve the linear system B.x = a.
19 //
20 // // You will hold your stats in a Stats stats_ class member:
21 // struct Stats : public StatsGroup {
22 // Stats() : StatsGroup("BasisFactorization"),
23 // solve_time("solve_time", this),
24 // input_vector_density("input_vector_density", this),
25 // estimated_accuracy("estimated_accuracy", this) {}
26 //
27 // TimeDistribution solve_time;
28 // RatioDistribution input_vector_density;
29 //
30 // // Values of a few components of B.x - a, updated on each solve.
31 // DoubleDistribution estimated_accuracy;
32 // }
33 //
34 // // You then add a few lines to your Solve() function:
35 // void Solve() {
36 // stats_.solve_time.StartTimer();
37 // stats_.input_vector_density.Add(ComputeDensity());
38 // ... // Do the work.
39 // stats_.estimated_accuracy.Add(EstimateAccuracy());
40 // stats_.solve_time.StopTimerAndAddElapsedTime();
41 // }
42 //
43 // // Now, calling stats_.StatString() will give you a summary of your stats:
44 // BasisFactorization {
45 // solve_time : num [min, max] average std_deviation total
46 // input_vector_density : num [min, max] average std_deviation
47 // estimated_accuracy : num [min, max] average std_deviation
48 // }
49 //
50 // For measuring time, another alternative is to use the SCOPED_TIME_STAT macro.
51 // In our example above, you don't need to define the solve_time distribution
52 // and you can just do:
53 //
54 // void Solve() {
55 // SCOPED_TIME_STAT(&stats_);
56 // ...
57 // }
58 //
59 // This automatically adds a TimeDistribution with name "Solve" to stats_ and
60 // times your function calls!
61 //
62 // IMPORTANT: The SCOPED_TIME_STAT() macro only does something if OR_STATS is
63 // defined, so you need to build your code with blaze build --copt='-DOR_STATS'.
64 // The idea is that by default the instrumentation is off. You can also use the
65 // macro IF_STATS_ENABLED() that does nothing if OR_STATS is not defined or just
66 // translates to its argument otherwise.
67 
68 #ifndef OR_TOOLS_UTIL_STATS_H_
69 #define OR_TOOLS_UTIL_STATS_H_
70 
71 #include <map>
72 #include <string>
73 #include <vector>
74 
75 #ifdef HAS_PERF_SUBSYSTEM
76 #include "absl/strings/str_replace.h"
77 #include "exegesis/exegesis/itineraries/perf_subsystem.h"
79 #endif // HAS_PERF_SUBSYSTEM
80 
81 #include "absl/strings/string_view.h"
82 #include "ortools/base/macros.h"
83 #include "ortools/base/timer.h"
84 
85 namespace operations_research {
86 
87 // Returns the current thread's total memory usage in an human-readable string.
88 std::string MemoryUsage();
89 
90 // Forward declaration.
91 class StatsGroup;
92 class TimeDistribution;
93 
94 // Base class for a statistic that can be pretty-printed.
95 class Stat {
96  public:
97  explicit Stat(absl::string_view name) : name_(name) {}
98 
99  // Also add this stat to the given group.
100  Stat(absl::string_view name, StatsGroup* group);
101  virtual ~Stat() {}
102 
103  // Only used for display purposes.
104  std::string Name() const { return name_; }
105 
106  // Returns a human-readable formatted line of the form "name:
107  // ValueAsString()".
108  std::string StatString() const;
109 
110  // At display, stats are displayed by decreasing priority, then decreasing
111  // Sum(), then alphabetical order.
112  // Used to group the stats per category (timing, ratio, etc..,).
113  virtual int Priority() const { return 0; }
114 
115  // By default return 0 for the sum. This makes it possible to sort stats by
116  // decreasing total time.
117  virtual double Sum() const { return 0; }
118 
119  // Prints information about this statistic.
120  virtual std::string ValueAsString() const = 0;
121 
122  // Is this stat worth printing? Usually false if nothing was measured.
123  virtual bool WorthPrinting() const = 0;
124 
125  // Reset this statistic to the same state as if it was newly created.
126  virtual void Reset() = 0;
127 
128  private:
129  const std::string name_;
130 };
131 
132 // Base class to print a nice summary of a group of statistics.
133 class StatsGroup {
134  public:
135  enum PrintOrder {
138  };
139 
140  explicit StatsGroup(absl::string_view name)
141  : name_(name), stats_(), time_distributions_() {}
142  ~StatsGroup();
143 
144  // Registers a Stat, which will appear in the string returned by StatString().
145  // The Stat object must live as long as this StatsGroup.
146  void Register(Stat* stat);
147 
148  // Returns this group name, followed by one line per Stat registered with this
149  // group (this includes the ones created by LookupOrCreateTimeDistribution()).
150  // Note that only the stats WorthPrinting() are printed.
151  std::string StatString() const;
152 
153  // Changes the print ordering (will affect the order in which the stats
154  // registered with this group are printed via StatString()).
155  void SetPrintOrder(PrintOrder print_order) { print_order_ = print_order; }
156 
157  // Returns and if needed creates and registers a TimeDistribution with the
158  // given name. Note that this involve a map lookup and his thus slower than
159  // directly accessing a TimeDistribution variable.
161 
162  // Calls Reset() on all the statistics registered with this group.
163  void Reset();
164 
165  private:
166  std::string name_;
168  std::vector<Stat*> stats_;
169  std::map<std::string, TimeDistribution*> time_distributions_;
170 
171  DISALLOW_COPY_AND_ASSIGN(StatsGroup);
172 };
173 
174 // Base class to track and compute statistics about the distribution of a
175 // sequence of double. We provide a few sub-classes below that differ in the way
176 // the values are added to the sequence and in the way the stats are printed.
177 class DistributionStat : public Stat {
178  public:
179  explicit DistributionStat(absl::string_view name);
181  DistributionStat(absl::string_view name, StatsGroup* group);
182  ~DistributionStat() override {}
183  void Reset() override;
184  bool WorthPrinting() const override { return num_ != 0; }
185 
186  // Implemented by the subclasses.
187  std::string ValueAsString() const override = 0;
188 
189  // Trivial statistics on all the values added so far.
190  double Sum() const override { return sum_; }
191  double Max() const { return max_; }
192  double Min() const { return min_; }
193  int64_t Num() const { return num_; }
194 
195  // Get the average of the distribution or 0.0 if empty.
196  double Average() const;
197 
198  // Get the standard deviation of the distribution or 0.0 if empty.
199  // We use the on-line algorithm of Welford described at
200  // http://en.wikipedia.org/wiki/Algorithms_for_calculating_variance
201  // TODO(user): We could also use on top the Kahan summation algorithm to be
202  // even more precise but a bit slower too.
203  double StdDeviation() const;
204 
205  protected:
206  // Adds a value to this sequence and updates the stats.
207  void AddToDistribution(double value);
208  double sum_;
209  double average_;
211  double min_;
212  double max_;
213  int64_t num_;
214 };
215 
216 // Statistic on the distribution of a sequence of running times.
217 // Also provides some facility to measure such time with the CPU cycle counter.
218 //
219 // TODO(user): Since we inherit from DistributionStat, we currently store the
220 // sum of CPU cycles as a double internally. A better option is to use int64_t
221 // because with the 53 bits of precision of a double, we will run into an issue
222 // if the sum of times reaches 52 days for a 2GHz processor.
224  public:
225  explicit TimeDistribution(absl::string_view name)
226  : DistributionStat(name), timer_() {}
228  TimeDistribution(absl::string_view name, StatsGroup* group)
229  : DistributionStat(name, group), timer_() {}
230  std::string ValueAsString() const override;
231 
232  // Time distributions have a high priority to be displayed first.
233  int Priority() const override { return 100; }
234 
235  // Internally the TimeDistribution stores CPU cycles (to do a bit less work
236  // on each StopTimerAndAddElapsedTime()). Use this function to convert
237  // all the statistics of DistributionStat into seconds.
238  static double CyclesToSeconds(double num_cycles);
239 
240  // Adds a time in seconds to this distribution.
241  void AddTimeInSec(double seconds);
242 
243  // Adds a time in CPU cycles to this distribution.
244  void AddTimeInCycles(double cycles);
245 
246  // Starts the timer in preparation of a StopTimerAndAddElapsedTime().
247  inline void StartTimer() { timer_.Restart(); }
248 
249  // Adds the elapsed time since the last StartTimer() to the distribution and
250  // returns this time in CPU cycles.
251  inline double StopTimerAndAddElapsedTime() {
252  const double cycles = static_cast<double>(timer_.GetCycles());
253  AddToDistribution(cycles);
254  return cycles;
255  }
256 
257  private:
258  // Converts and prints a number of cycles in an human readable way using the
259  // proper time unit depending on the value (ns, us, ms, s, m or h).
260  static std::string PrintCyclesAsTime(double cycles);
261  CycleTimer timer_;
262 };
263 
264 // Statistic on the distribution of a sequence of ratios, displayed as %.
266  public:
267  explicit RatioDistribution(absl::string_view name) : DistributionStat(name) {}
269  RatioDistribution(absl::string_view name, StatsGroup* group)
270  : DistributionStat(name, group) {}
271  std::string ValueAsString() const override;
272  void Add(double value);
273 };
274 
275 // Statistic on the distribution of a sequence of doubles.
277  public:
278  explicit DoubleDistribution(absl::string_view name)
279  : DistributionStat(name) {}
281  DoubleDistribution(absl::string_view name, StatsGroup* group)
282  : DistributionStat(name, group) {}
283  std::string ValueAsString() const override;
284  void Add(double value);
285 };
286 
287 // Statistic on the distribution of a sequence of integers.
289  public:
290  explicit IntegerDistribution(absl::string_view name)
291  : DistributionStat(name) {}
293  IntegerDistribution(absl::string_view name, StatsGroup* group)
294  : DistributionStat(name, group) {}
295  std::string ValueAsString() const override;
296  void Add(int64_t value);
297 };
298 
299 // Helper classes to time a block of code and add the result to a
300 // TimeDistribution. Calls StartTimer() on creation and
301 // StopTimerAndAddElapsedTime() on destruction.
302 //
303 // There are three classes with the same interface:
304 // * EnabledScopedTimeDistributionUpdater always collects the time stats of the
305 // scope in which it is defined. This class is used for stats that are always
306 // collected.
307 // * ScopedTimeDistributionUpdater collects the time stats only when OR_STATS is
308 // defined. This symbol should be used for collecting stats in places where
309 // the overhead of collecting the stats may hurt the performance of the
310 // algorithm.
311 // * DisabledScopedTimeDistributionUpdater is used to implement
312 // ScopedTimeDistributionUpdater when OR_STATS is not defined.
314  public:
315  // Note that this does not take ownership of the given stat.
317  : stat_(stat), also_update_(nullptr) {
318  stat->StartTimer();
319  }
321  const double cycles = stat_->StopTimerAndAddElapsedTime();
322  if (also_update_ != nullptr) {
323  also_update_->AddTimeInCycles(cycles);
324  }
325  }
326 
327  // Updates another TimeDistribution on destruction. This is useful to split
328  // a total time measurement in different categories:
329  //
330  // EnabledScopedTimeDistributionUpdater timer(&total_timer);
331  // ...
332  // switch (type) {
333  // case TypeA : timer.AlsoUpdate(&typeA_timer); break;
334  // case TypeB : timer.AlsoUpdate(&typeB_timer); break;
335  // }
336  void AlsoUpdate(TimeDistribution* also_update) { also_update_ = also_update; }
337 
338  private:
339  TimeDistribution* stat_;
340  TimeDistribution* also_update_;
341  DISALLOW_COPY_AND_ASSIGN(EnabledScopedTimeDistributionUpdater);
342 };
343 
345  public:
347  void AlsoUpdate(TimeDistribution* also_update) {}
348 
349  private:
350  DISALLOW_COPY_AND_ASSIGN(DisabledScopedTimeDistributionUpdater);
351 };
352 
353 #ifdef HAS_PERF_SUBSYSTEM
354 // Helper classes to count instructions during execution of a block of code and
355 // add print the results to logs.
356 //
357 // Note: To enable instruction counting on machines running Debian, execute the
358 // following commands to modify the permissions.
359 // sudo echo "1" > /proc/sys/kernel/perf_event_paranoid
360 // sudo echo "0" > /proc/sys/kernel/kptr_restrict
361 class EnabledScopedInstructionCounter {
362  public:
363  explicit EnabledScopedInstructionCounter(absl::string_view name,
364  TimeLimit* time_limit);
365  EnabledScopedInstructionCounter(const EnabledScopedInstructionCounter&) =
366  delete;
367  EnabledScopedInstructionCounter& operator=(
368  const EnabledScopedInstructionCounter&) = delete;
369  ~EnabledScopedInstructionCounter();
370 
371  // Used only for testing.
372  double ReadInstructionCount() { return ending_count_ - starting_count_; }
373 
374  private:
375  TimeLimit* time_limit_;
376  std::string name_;
377  double starting_count_;
378  double ending_count_;
379 };
380 #endif // HAS_PERF_SUBSYSTEM
381 
383  public:
384  explicit DisabledScopedInstructionCounter(absl::string_view) {}
386  delete;
388  const DisabledScopedInstructionCounter&) = delete;
389 };
390 
391 #ifdef OR_STATS
392 
394 #ifdef HAS_PERF_SUBSYSTEM
395 using ScopedInstructionCounter = EnabledScopedInstructionCounter;
396 #else // HAS_PERF_SUBSYSTEM
398 #endif // HAS_PERF_SUBSYSTEM
399 
400 // Simple macro to be used by a client that want to execute costly operations
401 // only if OR_STATS is defined.
402 #define IF_STATS_ENABLED(instructions) instructions
403 
404 // Measures the time from this macro line to the end of the scope and adds it
405 // to the distribution (from the given StatsGroup) with the same name as the
406 // enclosing function.
407 //
408 // Note(user): This adds more extra overhead around the measured code compared
409 // to defining your own TimeDistribution stat in your StatsGroup. About 80ns
410 // per measurement compared to about 20ns (as of 2012-06, on my workstation).
411 #define SCOPED_TIME_STAT(stats) \
412  operations_research::ScopedTimeDistributionUpdater scoped_time_stat( \
413  (stats)->LookupOrCreateTimeDistribution(__FUNCTION__))
414 
415 #ifdef HAS_PERF_SUBSYSTEM
416 
417 inline std::string RemoveOperationsResearchAndGlop(
418  const std::string& pretty_function) {
419  return strings::GlobalReplaceSubstrings(
420  pretty_function, {{"operations_research::", ""}, {"glop::", ""}});
421 }
422 
423 #define SCOPED_INSTRUCTION_COUNT(time_limit) \
424  operations_research::ScopedInstructionCounter scoped_instruction_count( \
425  RemoveOperationsResearchAndGlop(__PRETTY_FUNCTION__), time_limit)
426 
427 #else // !HAS_PERF_SUBSYSTEM
428 #define SCOPED_INSTRUCTION_COUNT(time_limit)
429 #endif // HAS_PERF_SUBSYSTEM
430 
431 #else // !OR_STATS
432 // If OR_STATS is not defined, we remove some instructions that may be time
433 // consuming.
434 
437 
438 #define IF_STATS_ENABLED(instructions)
439 #define SCOPED_TIME_STAT(stats)
440 #define SCOPED_INSTRUCTION_COUNT(time_limit)
441 
442 #endif // OR_STATS
443 
444 } // namespace operations_research
445 
446 #endif // OR_TOOLS_UTIL_STATS_H_
int64_t GetCycles() const
Definition: timer.h:77
void Restart()
Definition: timer.h:35
DisabledScopedInstructionCounter & operator=(const DisabledScopedInstructionCounter &)=delete
DisabledScopedInstructionCounter(const DisabledScopedInstructionCounter &)=delete
void AlsoUpdate(TimeDistribution *also_update)
Definition: stats.h:347
DisabledScopedTimeDistributionUpdater(TimeDistribution *stat)
Definition: stats.h:346
double Sum() const override
Definition: stats.h:190
std::string ValueAsString() const override=0
void AddToDistribution(double value)
Definition: stats.cc:156
bool WorthPrinting() const override
Definition: stats.h:184
DoubleDistribution(absl::string_view name, StatsGroup *group)
Definition: stats.h:281
DoubleDistribution(absl::string_view name)
Definition: stats.h:278
std::string ValueAsString() const override
Definition: stats.cc:230
void AlsoUpdate(TimeDistribution *also_update)
Definition: stats.h:336
EnabledScopedTimeDistributionUpdater(TimeDistribution *stat)
Definition: stats.h:316
IntegerDistribution(absl::string_view name, StatsGroup *group)
Definition: stats.h:293
IntegerDistribution(absl::string_view name)
Definition: stats.h:290
std::string ValueAsString() const override
Definition: stats.cc:239
RatioDistribution(absl::string_view name, StatsGroup *group)
Definition: stats.h:269
RatioDistribution(absl::string_view name)
Definition: stats.h:267
std::string ValueAsString() const override
Definition: stats.cc:222
virtual bool WorthPrinting() const =0
virtual std::string ValueAsString() const =0
std::string Name() const
Definition: stats.h:104
virtual void Reset()=0
virtual double Sum() const
Definition: stats.h:117
virtual int Priority() const
Definition: stats.h:113
Stat(absl::string_view name)
Definition: stats.h:97
std::string StatString() const
Definition: stats.cc:52
StatsGroup(absl::string_view name)
Definition: stats.h:140
void Register(Stat *stat)
Definition: stats.cc:56
void SetPrintOrder(PrintOrder print_order)
Definition: stats.h:155
TimeDistribution * LookupOrCreateTimeDistribution(std::string name)
Definition: stats.cc:120
std::string StatString() const
Definition: stats.cc:77
TimeDistribution(absl::string_view name, StatsGroup *group)
Definition: stats.h:228
static double CyclesToSeconds(double num_cycles)
Definition: stats.cc:181
void AddTimeInCycles(double cycles)
Definition: stats.cc:205
int Priority() const override
Definition: stats.h:233
void AddTimeInSec(double seconds)
Definition: stats.cc:199
TimeDistribution(absl::string_view name)
Definition: stats.h:225
std::string ValueAsString() const override
Definition: stats.cc:210
ModelSharedTimeLimit * time_limit
const std::string name
int64_t value
Collection of objects used to extend the Constraint Solver library.
std::string MemoryUsage()
Definition: stats.cc:31