stats.h 15.7 KB
Newer Older
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297 298 299 300 301 302 303 304 305 306 307 308 309 310 311 312 313 314 315 316 317 318 319 320 321 322 323 324 325 326 327 328 329 330 331 332 333 334 335 336 337 338 339 340 341 342 343 344 345 346 347 348 349 350 351 352 353 354 355 356 357 358 359 360 361 362 363 364 365 366 367 368 369 370 371 372 373 374 375 376 377 378 379 380 381 382 383 384 385 386 387 388 389 390 391 392 393 394 395 396 397 398 399 400 401 402 403 404 405 406 407 408 409 410 411 412 413 414 415 416 417 418 419 420 421 422 423 424 425 426 427 428 429 430 431 432 433 434 435 436 437 438
// Copyright 2010-2018 Google LLC
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
//     http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.

// Helper classes to track statistics of a program component.
//
// Usage example:
// // Suppose you have a class that contains a factorization of a matrix B and
// // a Solve() function to solve the linear system B.x = a.
//
// // You will hold your stats in a Stats stats_ class member:
// struct Stats : public StatsGroup {
//   Stats() : StatsGroup("BasisFactorization"),
//       solve_time("solve_time", this),
//       input_vector_density("input_vector_density", this),
//       estimated_accuracy("estimated_accuracy", this) {}
//
//   TimeDistribution solve_time;
//   RatioDistribution input_vector_density;
//
//   // Values of a few components of B.x - a, updated on each solve.
//   DoubleDistribution estimated_accuracy;
// }
//
// // You then add a few lines to your Solve() function:
// void Solve() {
//   stats_.solve_time.StartTimer();
//   stats_.input_vector_density.Add(ComputeDensity());
//   ...  // Do the work.
//   stats_.estimated_accuracy.Add(EstimateAccuracy());
//   stats_.solve_time.StopTimerAndAddElapsedTime();
// }
//
// // Now, calling stats_.StatString() will give you a summary of your stats:
// BasisFactorization {
//   solve_time           : num [min, max] average std_deviation total
//   input_vector_density : num [min, max] average std_deviation
//   estimated_accuracy   : num [min, max] average std_deviation
// }
//
// For measuring time, another alternative is to use the SCOPED_TIME_STAT macro.
// In our example above, you don't need to define the solve_time distribution
// and you can just do:
//
// void Solve() {
//   SCOPED_TIME_STAT(&stats_);
//   ...
// }
//
// This automatically adds a TimeDistribution with name "Solve" to stats_ and
// times your function calls!
//
// IMPORTANT: The SCOPED_TIME_STAT() macro only does something if OR_STATS is
// defined, so you need to build your code with blaze build --copt='-DOR_STATS'.
// The idea is that by default the instrumentation is off. You can also use the
// macro IF_STATS_ENABLED() that does nothing if OR_STATS is not defined or just
// translates to its argument otherwise.

#ifndef OR_TOOLS_UTIL_STATS_H_
#define OR_TOOLS_UTIL_STATS_H_

#include <map>
#include <string>

#ifdef HAS_PERF_SUBSYSTEM
#include "absl/strings/str_replace.h"
#include "exegesis/exegesis/itineraries/perf_subsystem.h"
#include "ortools/util/time_limit.h"
#endif  // HAS_PERF_SUBSYSTEM

#include "ortools/base/macros.h"
#include "ortools/base/timer.h"

namespace operations_research {

// Returns the current thread's total memory usage in an human-readable string.
std::string MemoryUsage();

// Forward declaration.
class StatsGroup;
class TimeDistribution;

// Base class for a statistic that can be pretty-printed.
class Stat {
 public:
  explicit Stat(const std::string& name) : name_(name) {}

  // Also add this stat to the given group.
  Stat(const std::string& name, StatsGroup* group);
  virtual ~Stat() {}

  // Only used for display purposes.
  std::string Name() const { return name_; }

  // Returns a human-readable formatted line of the form "name:
  // ValueAsString()".
  std::string StatString() const;

  // At display, stats are displayed by decreasing priority, then decreasing
  // Sum(), then alphabetical order.
  // Used to group the stats per category (timing, ratio, etc..,).
  virtual int Priority() const { return 0; }

  // By default return 0 for the sum. This makes it possible to sort stats by
  // decreasing total time.
  virtual double Sum() const { return 0; }

  // Prints information about this statistic.
  virtual std::string ValueAsString() const = 0;

  // Is this stat worth printing? Usually false if nothing was measured.
  virtual bool WorthPrinting() const = 0;

  // Reset this statistic to the same state as if it was newly created.
  virtual void Reset() = 0;

 private:
  const std::string name_;
};

// Base class to print a nice summary of a group of statistics.
class StatsGroup {
 public:
  enum PrintOrder {
    SORT_BY_PRIORITY_THEN_VALUE = 0,
    SORT_BY_NAME = 1,
  };

  explicit StatsGroup(const std::string& name)
      : name_(name), stats_(), time_distributions_() {}
  ~StatsGroup();

  // Registers a Stat, which will appear in the string returned by StatString().
  // The Stat object must live as long as this StatsGroup.
  void Register(Stat* stat);

  // Returns this group name, followed by one line per Stat registered with this
  // group (this includes the ones created by LookupOrCreateTimeDistribution()).
  // Note that only the stats WorthPrinting() are printed.
  std::string StatString() const;

  // Changes the print ordering (will affect the order in which the stats
  // registered with this group are printed via StatString()).
  void SetPrintOrder(PrintOrder print_order) { print_order_ = print_order; }

  // Returns and if needed creates and registers a TimeDistribution with the
  // given name. Note that this involve a map lookup and his thus slower than
  // directly accessing a TimeDistribution variable.
  TimeDistribution* LookupOrCreateTimeDistribution(std::string name);

  // Calls Reset() on all the statistics registered with this group.
  void Reset();

 private:
  std::string name_;
  PrintOrder print_order_ = SORT_BY_PRIORITY_THEN_VALUE;
  std::vector<Stat*> stats_;
  std::map<std::string, TimeDistribution*> time_distributions_;

  DISALLOW_COPY_AND_ASSIGN(StatsGroup);
};

// Base class to track and compute statistics about the distribution of a
// sequence of double. We provide a few sub-classes below that differ in the way
// the values are added to the sequence and in the way the stats are printed.
class DistributionStat : public Stat {
 public:
  explicit DistributionStat(const std::string& name);
  DistributionStat(const std::string& name, StatsGroup* group);
  ~DistributionStat() override {}
  void Reset() override;
  bool WorthPrinting() const override { return num_ != 0; }

  // Implemented by the subclasses.
  std::string ValueAsString() const override = 0;

  // Trivial statistics on all the values added so far.
  double Sum() const override { return sum_; }
  double Max() const { return max_; }
  double Min() const { return min_; }
  int64 Num() const { return num_; }

  // Get the average of the distribution or 0.0 if empty.
  double Average() const;

  // Get the standard deviation of the distribution or 0.0 if empty.
  // We use the on-line algorithm of Welford described at
  // http://en.wikipedia.org/wiki/Algorithms_for_calculating_variance
  // TODO(user): We could also use on top the Kahan summation algorithm to be
  // even more precise but a bit slower too.
  double StdDeviation() const;

 protected:
  // Adds a value to this sequence and updates the stats.
  void AddToDistribution(double value);
  double sum_;
  double average_;
  double sum_squares_from_average_;
  double min_;
  double max_;
  int64 num_;
};

// Statistic on the distribution of a sequence of running times.
// Also provides some facility to measure such time with the CPU cycle counter.
//
// TODO(user): Since we inherit from DistributionStat, we currently store the
// sum of CPU cycles as a double internally. A better option is to use int64
// because with the 53 bits of precision of a double, we will run into an issue
// if the sum of times reaches 52 days for a 2GHz processor.
class TimeDistribution : public DistributionStat {
 public:
  explicit TimeDistribution(const std::string& name)
      : DistributionStat(name), timer_() {}
  TimeDistribution(const std::string& name, StatsGroup* group)
      : DistributionStat(name, group), timer_() {}
  std::string ValueAsString() const override;

  // Time distributions have a high priority to be displayed first.
  int Priority() const override { return 100; }

  // Internaly the TimeDistribution stores CPU cycles (to do a bit less work
  // on each StopTimerAndAddElapsedTime()). Use this function to convert
  // all the statistics of DistributionStat into seconds.
  static double CyclesToSeconds(double num_cycles);

  // Adds a time in seconds to this distribution.
  void AddTimeInSec(double seconds);

  // Adds a time in CPU cycles to this distribution.
  void AddTimeInCycles(double cycles);

  // Starts the timer in preparation of a StopTimerAndAddElapsedTime().
  inline void StartTimer() { timer_.Restart(); }

  // Adds the elapsed time since the last StartTimer() to the distribution and
  // returns this time in CPU cycles.
  inline double StopTimerAndAddElapsedTime() {
    const double cycles = static_cast<double>(timer_.GetCycles());
    AddToDistribution(cycles);
    return cycles;
  }

 private:
  // Converts and prints a number of cycles in an human readable way using the
  // proper time unit depending on the value (ns, us, ms, s, m or h).
  static std::string PrintCyclesAsTime(double cycles);
  CycleTimer timer_;
};

// Statistic on the distribution of a sequence of ratios, displayed as %.
class RatioDistribution : public DistributionStat {
 public:
  explicit RatioDistribution(const std::string& name)
      : DistributionStat(name) {}
  RatioDistribution(const std::string& name, StatsGroup* group)
      : DistributionStat(name, group) {}
  std::string ValueAsString() const override;
  void Add(double value);
};

// Statistic on the distribution of a sequence of doubles.
class DoubleDistribution : public DistributionStat {
 public:
  explicit DoubleDistribution(const std::string& name)
      : DistributionStat(name) {}
  DoubleDistribution(const std::string& name, StatsGroup* group)
      : DistributionStat(name, group) {}
  std::string ValueAsString() const override;
  void Add(double value);
};

// Statistic on the distribution of a sequence of integers.
class IntegerDistribution : public DistributionStat {
 public:
  explicit IntegerDistribution(const std::string& name)
      : DistributionStat(name) {}
  IntegerDistribution(const std::string& name, StatsGroup* group)
      : DistributionStat(name, group) {}
  std::string ValueAsString() const override;
  void Add(int64 value);
};

// Helper classes to time a block of code and add the result to a
// TimeDistribution. Calls StartTimer() on creation and
// StopTimerAndAddElapsedTime() on destruction.
//
// There are three classes with the same interface:
// * EnabledScopedTimeDistributionUpdater always collects the time stats of the
//   scope in which it is defined. This class is used for stats that are always
//   collected.
// * ScopedTimeDistributionUpdater collects the time stats only when OR_STATS is
//   defined. This symbol should be used for collecting stats in places where
//   the overhead of collecting the stats may hurt the performance of the
//   algorithm.
// * DisabledScopedTimeDistributionUpdater is used to implement
//   ScopedTimeDistributionUpdater when OR_STATS is not defined.
class EnabledScopedTimeDistributionUpdater {
 public:
  // Note that this does not take ownership of the given stat.
  explicit EnabledScopedTimeDistributionUpdater(TimeDistribution* stat)
      : stat_(stat), also_update_(nullptr) {
    stat->StartTimer();
  }
  ~EnabledScopedTimeDistributionUpdater() {
    const double cycles = stat_->StopTimerAndAddElapsedTime();
    if (also_update_ != nullptr) {
      also_update_->AddTimeInCycles(cycles);
    }
  }

  // Updates another TimeDistribution on destruction. This is useful to split
  // a total time measurement in different categories:
  //
  // EnabledScopedTimeDistributionUpdater timer(&total_timer);
  // ...
  // switch (type) {
  //   case TypeA : timer.AlsoUpdate(&typeA_timer); break;
  //   case TypeB : timer.AlsoUpdate(&typeB_timer); break;
  // }
  void AlsoUpdate(TimeDistribution* also_update) { also_update_ = also_update; }

 private:
  TimeDistribution* stat_;
  TimeDistribution* also_update_;
  DISALLOW_COPY_AND_ASSIGN(EnabledScopedTimeDistributionUpdater);
};

class DisabledScopedTimeDistributionUpdater {
 public:
  explicit DisabledScopedTimeDistributionUpdater(TimeDistribution* stat) {}
  void AlsoUpdate(TimeDistribution* also_update) {}

 private:
  DISALLOW_COPY_AND_ASSIGN(DisabledScopedTimeDistributionUpdater);
};

#ifdef HAS_PERF_SUBSYSTEM
// Helper classes to count instructions during execution of a block of code and
// add print the results to logs.
//
// Note: To enable instruction counting on machines running Debian, execute the
// following commands to modify the permissions.
//   sudo echo "1" > /proc/sys/kernel/perf_event_paranoid
//   sudo echo "0" > /proc/sys/kernel/kptr_restrict
class EnabledScopedInstructionCounter {
 public:
  explicit EnabledScopedInstructionCounter(const std::string& name,
                                           TimeLimit* time_limit);
  EnabledScopedInstructionCounter(const EnabledScopedInstructionCounter&) =
      delete;
  EnabledScopedInstructionCounter& operator=(
      const EnabledScopedInstructionCounter&) = delete;
  ~EnabledScopedInstructionCounter();

  // Used only for testing.
  double ReadInstructionCount() { return ending_count_ - starting_count_; }

 private:
  TimeLimit* time_limit_;
  std::string name_;
  double starting_count_;
  double ending_count_;
};
#endif  // HAS_PERF_SUBSYSTEM

class DisabledScopedInstructionCounter {
 public:
  explicit DisabledScopedInstructionCounter(const std::string& name) {}
  DisabledScopedInstructionCounter(const DisabledScopedInstructionCounter&) =
      delete;
  DisabledScopedInstructionCounter& operator=(
      const DisabledScopedInstructionCounter&) = delete;
};

#ifdef OR_STATS

using ScopedTimeDistributionUpdater = EnabledScopedTimeDistributionUpdater;
#ifdef HAS_PERF_SUBSYSTEM
using ScopedInstructionCounter = EnabledScopedInstructionCounter;
#else   // HAS_PERF_SUBSYSTEM
using ScopedInstructionCounter = DisabledScopedInstructionCounter;
#endif  // HAS_PERF_SUBSYSTEM

// Simple macro to be used by a client that want to execute costly operations
// only if OR_STATS is defined.
#define IF_STATS_ENABLED(instructions) instructions

// Measures the time from this macro line to the end of the scope and adds it
// to the distribution (from the given StatsGroup) with the same name as the
// enclosing function.
//
// Note(user): This adds more extra overhead around the measured code compared
// to defining your own TimeDistribution stat in your StatsGroup. About 80ns
// per measurement compared to about 20ns (as of 2012-06, on my workstation).
#define SCOPED_TIME_STAT(stats)                                        \
  operations_research::ScopedTimeDistributionUpdater scoped_time_stat( \
      (stats)->LookupOrCreateTimeDistribution(__FUNCTION__))

#ifdef HAS_PERF_SUBSYSTEM

inline std::string RemoveOperationsResearchAndGlop(
    const std::string& pretty_function) {
  return strings::GlobalReplaceSubstrings(
      pretty_function, {{"operations_research::", ""}, {"glop::", ""}});
}

#define SCOPED_INSTRUCTION_COUNT(time_limit)                              \
  operations_research::ScopedInstructionCounter scoped_instruction_count( \
      RemoveOperationsResearchAndGlop(__PRETTY_FUNCTION__), time_limit)

#endif  // HAS_PERF_SUBSYSTEM

#else  // OR_STATS
// If OR_STATS is not defined, we remove some instructions that may be time
// consuming.

using ScopedTimeDistributionUpdater = DisabledScopedTimeDistributionUpdater;
using ScopedInstructionCounter = DisabledScopedInstructionCounter;

#define IF_STATS_ENABLED(instructions)
#define SCOPED_TIME_STAT(stats)
#define SCOPED_INSTRUCTION_COUNT(time_limit)

#endif  // OR_STATS

}  // namespace operations_research

#endif  // OR_TOOLS_UTIL_STATS_H_