OR-Tools  8.2
stats.h
Go to the documentation of this file.
1// Copyright 2010-2018 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
74#ifdef HAS_PERF_SUBSYSTEM
75#include "absl/strings/str_replace.h"
76#include "exegesis/exegesis/itineraries/perf_subsystem.h"
78#endif // HAS_PERF_SUBSYSTEM
79
80#include "ortools/base/macros.h"
81#include "ortools/base/timer.h"
82
83namespace operations_research {
84
85// Returns the current thread's total memory usage in an human-readable string.
86std::string MemoryUsage();
87
88// Forward declaration.
89class StatsGroup;
90class TimeDistribution;
91
92// Base class for a statistic that can be pretty-printed.
93class Stat {
94 public:
95 explicit Stat(const std::string& name) : name_(name) {}
96
97 // Also add this stat to the given group.
98 Stat(const std::string& name, StatsGroup* group);
99 virtual ~Stat() {}
100
101 // Only used for display purposes.
102 std::string Name() const { return name_; }
103
104 // Returns a human-readable formatted line of the form "name:
105 // ValueAsString()".
106 std::string StatString() const;
107
108 // At display, stats are displayed by decreasing priority, then decreasing
109 // Sum(), then alphabetical order.
110 // Used to group the stats per category (timing, ratio, etc..,).
111 virtual int Priority() const { return 0; }
112
113 // By default return 0 for the sum. This makes it possible to sort stats by
114 // decreasing total time.
115 virtual double Sum() const { return 0; }
116
117 // Prints information about this statistic.
118 virtual std::string ValueAsString() const = 0;
119
120 // Is this stat worth printing? Usually false if nothing was measured.
121 virtual bool WorthPrinting() const = 0;
122
123 // Reset this statistic to the same state as if it was newly created.
124 virtual void Reset() = 0;
125
126 private:
127 const std::string name_;
128};
129
130// Base class to print a nice summary of a group of statistics.
132 public:
136 };
137
138 explicit StatsGroup(const std::string& name)
139 : name_(name), stats_(), time_distributions_() {}
140 ~StatsGroup();
141
142 // Registers a Stat, which will appear in the string returned by StatString().
143 // The Stat object must live as long as this StatsGroup.
144 void Register(Stat* stat);
145
146 // Returns this group name, followed by one line per Stat registered with this
147 // group (this includes the ones created by LookupOrCreateTimeDistribution()).
148 // Note that only the stats WorthPrinting() are printed.
149 std::string StatString() const;
150
151 // Changes the print ordering (will affect the order in which the stats
152 // registered with this group are printed via StatString()).
153 void SetPrintOrder(PrintOrder print_order) { print_order_ = print_order; }
154
155 // Returns and if needed creates and registers a TimeDistribution with the
156 // given name. Note that this involve a map lookup and his thus slower than
157 // directly accessing a TimeDistribution variable.
159
160 // Calls Reset() on all the statistics registered with this group.
161 void Reset();
162
163 private:
164 std::string name_;
166 std::vector<Stat*> stats_;
167 std::map<std::string, TimeDistribution*> time_distributions_;
168
169 DISALLOW_COPY_AND_ASSIGN(StatsGroup);
170};
171
172// Base class to track and compute statistics about the distribution of a
173// sequence of double. We provide a few sub-classes below that differ in the way
174// the values are added to the sequence and in the way the stats are printed.
175class DistributionStat : public Stat {
176 public:
177 explicit DistributionStat(const std::string& name);
179 DistributionStat(const std::string& name, StatsGroup* group);
180 ~DistributionStat() override {}
181 void Reset() override;
182 bool WorthPrinting() const override { return num_ != 0; }
183
184 // Implemented by the subclasses.
185 std::string ValueAsString() const override = 0;
186
187 // Trivial statistics on all the values added so far.
188 double Sum() const override { return sum_; }
189 double Max() const { return max_; }
190 double Min() const { return min_; }
191 int64 Num() const { return num_; }
192
193 // Get the average of the distribution or 0.0 if empty.
194 double Average() const;
195
196 // Get the standard deviation of the distribution or 0.0 if empty.
197 // We use the on-line algorithm of Welford described at
198 // http://en.wikipedia.org/wiki/Algorithms_for_calculating_variance
199 // TODO(user): We could also use on top the Kahan summation algorithm to be
200 // even more precise but a bit slower too.
201 double StdDeviation() const;
202
203 protected:
204 // Adds a value to this sequence and updates the stats.
205 void AddToDistribution(double value);
206 double sum_;
207 double average_;
209 double min_;
210 double max_;
212};
213
214// Statistic on the distribution of a sequence of running times.
215// Also provides some facility to measure such time with the CPU cycle counter.
216//
217// TODO(user): Since we inherit from DistributionStat, we currently store the
218// sum of CPU cycles as a double internally. A better option is to use int64
219// because with the 53 bits of precision of a double, we will run into an issue
220// if the sum of times reaches 52 days for a 2GHz processor.
222 public:
223 explicit TimeDistribution(const std::string& name)
224 : DistributionStat(name), timer_() {}
226 TimeDistribution(const std::string& name, StatsGroup* group)
227 : DistributionStat(name, group), timer_() {}
228 std::string ValueAsString() const override;
229
230 // Time distributions have a high priority to be displayed first.
231 int Priority() const override { return 100; }
232
233 // Internaly the TimeDistribution stores CPU cycles (to do a bit less work
234 // on each StopTimerAndAddElapsedTime()). Use this function to convert
235 // all the statistics of DistributionStat into seconds.
236 static double CyclesToSeconds(double num_cycles);
237
238 // Adds a time in seconds to this distribution.
239 void AddTimeInSec(double seconds);
240
241 // Adds a time in CPU cycles to this distribution.
242 void AddTimeInCycles(double cycles);
243
244 // Starts the timer in preparation of a StopTimerAndAddElapsedTime().
245 inline void StartTimer() { timer_.Restart(); }
246
247 // Adds the elapsed time since the last StartTimer() to the distribution and
248 // returns this time in CPU cycles.
250 const double cycles = static_cast<double>(timer_.GetCycles());
251 AddToDistribution(cycles);
252 return cycles;
253 }
254
255 private:
256 // Converts and prints a number of cycles in an human readable way using the
257 // proper time unit depending on the value (ns, us, ms, s, m or h).
258 static std::string PrintCyclesAsTime(double cycles);
259 CycleTimer timer_;
260};
261
262// Statistic on the distribution of a sequence of ratios, displayed as %.
264 public:
265 explicit RatioDistribution(const std::string& name)
268 RatioDistribution(const std::string& name, StatsGroup* group)
269 : DistributionStat(name, group) {}
270 std::string ValueAsString() const override;
271 void Add(double value);
272};
273
274// Statistic on the distribution of a sequence of doubles.
276 public:
277 explicit DoubleDistribution(const std::string& name)
280 DoubleDistribution(const std::string& name, StatsGroup* group)
281 : DistributionStat(name, group) {}
282 std::string ValueAsString() const override;
283 void Add(double value);
284};
285
286// Statistic on the distribution of a sequence of integers.
288 public:
289 explicit IntegerDistribution(const std::string& name)
292 IntegerDistribution(const std::string& name, StatsGroup* group)
293 : DistributionStat(name, group) {}
294 std::string ValueAsString() const override;
295 void Add(int64 value);
296};
297
298// Helper classes to time a block of code and add the result to a
299// TimeDistribution. Calls StartTimer() on creation and
300// StopTimerAndAddElapsedTime() on destruction.
301//
302// There are three classes with the same interface:
303// * EnabledScopedTimeDistributionUpdater always collects the time stats of the
304// scope in which it is defined. This class is used for stats that are always
305// collected.
306// * ScopedTimeDistributionUpdater collects the time stats only when OR_STATS is
307// defined. This symbol should be used for collecting stats in places where
308// the overhead of collecting the stats may hurt the performance of the
309// algorithm.
310// * DisabledScopedTimeDistributionUpdater is used to implement
311// ScopedTimeDistributionUpdater when OR_STATS is not defined.
313 public:
314 // Note that this does not take ownership of the given stat.
316 : stat_(stat), also_update_(nullptr) {
317 stat->StartTimer();
318 }
320 const double cycles = stat_->StopTimerAndAddElapsedTime();
321 if (also_update_ != nullptr) {
322 also_update_->AddTimeInCycles(cycles);
323 }
324 }
325
326 // Updates another TimeDistribution on destruction. This is useful to split
327 // a total time measurement in different categories:
328 //
329 // EnabledScopedTimeDistributionUpdater timer(&total_timer);
330 // ...
331 // switch (type) {
332 // case TypeA : timer.AlsoUpdate(&typeA_timer); break;
333 // case TypeB : timer.AlsoUpdate(&typeB_timer); break;
334 // }
335 void AlsoUpdate(TimeDistribution* also_update) { also_update_ = also_update; }
336
337 private:
338 TimeDistribution* stat_;
339 TimeDistribution* also_update_;
340 DISALLOW_COPY_AND_ASSIGN(EnabledScopedTimeDistributionUpdater);
341};
342
344 public:
346 void AlsoUpdate(TimeDistribution* also_update) {}
347
348 private:
349 DISALLOW_COPY_AND_ASSIGN(DisabledScopedTimeDistributionUpdater);
350};
351
352#ifdef HAS_PERF_SUBSYSTEM
353// Helper classes to count instructions during execution of a block of code and
354// add print the results to logs.
355//
356// Note: To enable instruction counting on machines running Debian, execute the
357// following commands to modify the permissions.
358// sudo echo "1" > /proc/sys/kernel/perf_event_paranoid
359// sudo echo "0" > /proc/sys/kernel/kptr_restrict
360class EnabledScopedInstructionCounter {
361 public:
362 explicit EnabledScopedInstructionCounter(const std::string& name,
363 TimeLimit* time_limit);
364 EnabledScopedInstructionCounter(const EnabledScopedInstructionCounter&) =
365 delete;
366 EnabledScopedInstructionCounter& operator=(
367 const EnabledScopedInstructionCounter&) = delete;
368 ~EnabledScopedInstructionCounter();
369
370 // Used only for testing.
371 double ReadInstructionCount() { return ending_count_ - starting_count_; }
372
373 private:
374 TimeLimit* time_limit_;
375 std::string name_;
376 double starting_count_;
377 double ending_count_;
378};
379#endif // HAS_PERF_SUBSYSTEM
380
382 public:
383 explicit DisabledScopedInstructionCounter(const std::string& name) {}
385 delete;
387 const DisabledScopedInstructionCounter&) = delete;
388};
389
390#ifdef OR_STATS
391
393#ifdef HAS_PERF_SUBSYSTEM
394using ScopedInstructionCounter = EnabledScopedInstructionCounter;
395#else // HAS_PERF_SUBSYSTEM
397#endif // HAS_PERF_SUBSYSTEM
398
399// Simple macro to be used by a client that want to execute costly operations
400// only if OR_STATS is defined.
401#define IF_STATS_ENABLED(instructions) instructions
402
403// Measures the time from this macro line to the end of the scope and adds it
404// to the distribution (from the given StatsGroup) with the same name as the
405// enclosing function.
406//
407// Note(user): This adds more extra overhead around the measured code compared
408// to defining your own TimeDistribution stat in your StatsGroup. About 80ns
409// per measurement compared to about 20ns (as of 2012-06, on my workstation).
410#define SCOPED_TIME_STAT(stats) \
411 operations_research::ScopedTimeDistributionUpdater scoped_time_stat( \
412 (stats)->LookupOrCreateTimeDistribution(__FUNCTION__))
413
414#ifdef HAS_PERF_SUBSYSTEM
415
416inline std::string RemoveOperationsResearchAndGlop(
417 const std::string& pretty_function) {
418 return strings::GlobalReplaceSubstrings(
419 pretty_function, {{"operations_research::", ""}, {"glop::", ""}});
420}
421
422#define SCOPED_INSTRUCTION_COUNT(time_limit) \
423 operations_research::ScopedInstructionCounter scoped_instruction_count( \
424 RemoveOperationsResearchAndGlop(__PRETTY_FUNCTION__), time_limit)
425
426#else // !HAS_PERF_SUBSYSTEM
427#define SCOPED_INSTRUCTION_COUNT(time_limit)
428#endif // HAS_PERF_SUBSYSTEM
429
430#else // !OR_STATS
431// If OR_STATS is not defined, we remove some instructions that may be time
432// consuming.
433
436
437#define IF_STATS_ENABLED(instructions)
438#define SCOPED_TIME_STAT(stats)
439#define SCOPED_INSTRUCTION_COUNT(time_limit)
440
441#endif // OR_STATS
442
443} // namespace operations_research
444
445#endif // OR_TOOLS_UTIL_STATS_H_
int64 GetCycles() const
Definition: timer.h:76
void Restart()
Definition: timer.h:35
DisabledScopedInstructionCounter & operator=(const DisabledScopedInstructionCounter &)=delete
DisabledScopedInstructionCounter(const std::string &name)
Definition: stats.h:383
DisabledScopedInstructionCounter(const DisabledScopedInstructionCounter &)=delete
void AlsoUpdate(TimeDistribution *also_update)
Definition: stats.h:346
DisabledScopedTimeDistributionUpdater(TimeDistribution *stat)
Definition: stats.h:345
double Sum() const override
Definition: stats.h:188
std::string ValueAsString() const override=0
void AddToDistribution(double value)
Definition: stats.cc:150
bool WorthPrinting() const override
Definition: stats.h:182
DoubleDistribution(const std::string &name)
Definition: stats.h:277
DoubleDistribution(const std::string &name, StatsGroup *group)
Definition: stats.h:280
std::string ValueAsString() const override
Definition: stats.cc:224
void AlsoUpdate(TimeDistribution *also_update)
Definition: stats.h:335
EnabledScopedTimeDistributionUpdater(TimeDistribution *stat)
Definition: stats.h:315
IntegerDistribution(const std::string &name)
Definition: stats.h:289
IntegerDistribution(const std::string &name, StatsGroup *group)
Definition: stats.h:292
std::string ValueAsString() const override
Definition: stats.cc:233
RatioDistribution(const std::string &name, StatsGroup *group)
Definition: stats.h:268
RatioDistribution(const std::string &name)
Definition: stats.h:265
std::string ValueAsString() const override
Definition: stats.cc:216
virtual bool WorthPrinting() const =0
virtual std::string ValueAsString() const =0
std::string Name() const
Definition: stats.h:102
virtual void Reset()=0
virtual double Sum() const
Definition: stats.h:115
virtual int Priority() const
Definition: stats.h:111
Stat(const std::string &name)
Definition: stats.h:95
std::string StatString() const
Definition: stats.cc:46
void Register(Stat *stat)
Definition: stats.cc:50
void SetPrintOrder(PrintOrder print_order)
Definition: stats.h:153
TimeDistribution * LookupOrCreateTimeDistribution(std::string name)
Definition: stats.cc:114
StatsGroup(const std::string &name)
Definition: stats.h:138
std::string StatString() const
Definition: stats.cc:71
TimeDistribution(const std::string &name, StatsGroup *group)
Definition: stats.h:226
static double CyclesToSeconds(double num_cycles)
Definition: stats.cc:175
void AddTimeInCycles(double cycles)
Definition: stats.cc:199
TimeDistribution(const std::string &name)
Definition: stats.h:223
int Priority() const override
Definition: stats.h:231
void AddTimeInSec(double seconds)
Definition: stats.cc:193
std::string ValueAsString() const override
Definition: stats.cc:204
SharedTimeLimit * time_limit
const std::string name
int64 value
int64_t int64
The vehicle routing library lets one model and solve generic vehicle routing problems ranging from th...
std::string MemoryUsage()
Definition: stats.cc:25