compiler-rt/lib/scudo/standalone/timing.h

   1 //===-- timing.h ------------------------------------------------*- C++ -*-===//
   2 //
   3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
   4 // See https://llvm.org/LICENSE.txt for license information.
   5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
   6 //
   7 //===----------------------------------------------------------------------===//
   8
   9 #ifndef SCUDO_TIMING_H_
  10 #define SCUDO_TIMING_H_
  11
  12 #include "common.h"
  13 #include "mutex.h"
  14 #include "string_utils.h"
  15 #include "thread_annotations.h"
  16
  17 #include <inttypes.h>
  18 #include <string.h>
  19
  20 namespace scudo {
  21
  22 class TimingManager;
  23
  24 // A simple timer for evaluating execution time of code snippets. It can be used
  25 // along with TimingManager or standalone.
  26 class Timer {
  27 public:
  28   // The use of Timer without binding to a TimingManager is supposed to do the
  29   // timer logging manually. Otherwise, TimingManager will do the logging stuff
  30   // for you.
  31   Timer() = default;
  32   Timer(Timer &&Other)
  33       : StartTime(0), AccTime(Other.AccTime), Manager(Other.Manager),
  34         HandleId(Other.HandleId) {
  35     Other.Manager = nullptr;
  36   }
  37
  38   Timer(const Timer &) = delete;
  39
  40   ~Timer();
  41
  42   void start() {
  43     CHECK_EQ(StartTime, 0U);
  44     StartTime = getMonotonicTime();
  45   }
  46   void stop() {
  47     AccTime += getMonotonicTime() - StartTime;
  48     StartTime = 0;
  49   }
  50   u64 getAccumulatedTime() const { return AccTime; }
  51
  52   // Unset the bound TimingManager so that we don't report the data back. This
  53   // is useful if we only want to track subset of certain scope events.
  54   void ignore() {
  55     StartTime = 0;
  56     AccTime = 0;
  57     Manager = nullptr;
  58   }
  59
  60 protected:
  61   friend class TimingManager;
  62   Timer(TimingManager &Manager, u32 HandleId)
  63       : Manager(&Manager), HandleId(HandleId) {}
  64
  65   u64 StartTime = 0;
  66   u64 AccTime = 0;
  67   TimingManager *Manager = nullptr;
  68   u32 HandleId;
  69 };
  70
  71 // A RAII-style wrapper for easy scope execution measurement. Note that in order
  72 // not to take additional space for the message like `Name`. It only works with
  73 // TimingManager.
  74 class ScopedTimer : public Timer {
  75 public:
  76   ScopedTimer(TimingManager &Manager, const char *Name);
  77   ScopedTimer(TimingManager &Manager, const Timer &Nest, const char *Name);
  78   ~ScopedTimer() { stop(); }
  79 };
  80
  81 // In Scudo, the execution time of single run of code snippets may not be
  82 // useful, we are more interested in the average time from several runs.
  83 // TimingManager lets the registered timer report their data and reports the
  84 // average execution time for each timer periodically.
  85 class TimingManager {
  86 public:
  87   TimingManager(u32 PrintingInterval = DefaultPrintingInterval)
  88       : PrintingInterval(PrintingInterval) {}
  89   ~TimingManager() {
  90     if (NumAllocatedTimers != 0)
  91       printAll();
  92   }
  93
  94   Timer getOrCreateTimer(const char *Name) EXCLUDES(Mutex) {
  95     ScopedLock L(Mutex);
  96
  97     CHECK_LT(strlen(Name), MaxLenOfTimerName);
  98     for (u32 I = 0; I < NumAllocatedTimers; ++I) {
  99       if (strncmp(Name, Timers[I].Name, MaxLenOfTimerName) == 0)
 100         return Timer(*this, I);
 101     }
 102
 103     CHECK_LT(NumAllocatedTimers, MaxNumberOfTimers);
 104     strncpy(Timers[NumAllocatedTimers].Name, Name, MaxLenOfTimerName);
 105     TimerRecords[NumAllocatedTimers].AccumulatedTime = 0;
 106     TimerRecords[NumAllocatedTimers].Occurrence = 0;
 107     return Timer(*this, NumAllocatedTimers++);
 108   }
 109
 110   // Add a sub-Timer associated with another Timer. This is used when we want to
 111   // detail the execution time in the scope of a Timer.
 112   // For example,
 113   //   void Foo() {
 114   //     // T1 records the time spent in both first and second tasks.
 115   //     ScopedTimer T1(getTimingManager(), "Task1");
 116   //     {
 117   //       // T2 records the time spent in first task
 118   //       ScopedTimer T2(getTimingManager, T1, "Task2");
 119   //       // Do first task.
 120   //     }
 121   //     // Do second task.
 122   //   }
 123   //
 124   // The report will show proper indents to indicate the nested relation like,
 125   //   -- Average Operation Time -- -- Name (# of Calls) --
 126   //             10.0(ns)            Task1 (1)
 127   //              5.0(ns)              Task2 (1)
 128   Timer nest(const Timer &T, const char *Name) EXCLUDES(Mutex) {
 129     CHECK_EQ(T.Manager, this);
 130     Timer Nesting = getOrCreateTimer(Name);
 131
 132     ScopedLock L(Mutex);
 133     CHECK_NE(Nesting.HandleId, T.HandleId);
 134     Timers[Nesting.HandleId].Nesting = T.HandleId;
 135     return Nesting;
 136   }
 137
 138   void report(const Timer &T) EXCLUDES(Mutex) {
 139     ScopedLock L(Mutex);
 140
 141     const u32 HandleId = T.HandleId;
 142     CHECK_LT(HandleId, MaxNumberOfTimers);
 143     TimerRecords[HandleId].AccumulatedTime += T.getAccumulatedTime();
 144     ++TimerRecords[HandleId].Occurrence;
 145     ++NumEventsReported;
 146     if (NumEventsReported % PrintingInterval == 0)
 147       printAllImpl();
 148   }
 149
 150   void printAll() EXCLUDES(Mutex) {
 151     ScopedLock L(Mutex);
 152     printAllImpl();
 153   }
 154
 155 private:
 156   void printAllImpl() REQUIRES(Mutex) {
 157     static char NameHeader[] = "-- Name (# of Calls) --";
 158     static char AvgHeader[] = "-- Average Operation Time --";
 159     ScopedString Str;
 160     Str.append("%-15s %-15s\n", AvgHeader, NameHeader);
 161
 162     for (u32 I = 0; I < NumAllocatedTimers; ++I) {
 163       if (Timers[I].Nesting != MaxNumberOfTimers)
 164         continue;
 165       printImpl(Str, I);
 166     }
 167
 168     Str.output();
 169   }
 170
 171   void printImpl(ScopedString &Str, const u32 HandleId,
 172                  const u32 ExtraIndent = 0) REQUIRES(Mutex) {
 173     const u64 AccumulatedTime = TimerRecords[HandleId].AccumulatedTime;
 174     const u64 Occurrence = TimerRecords[HandleId].Occurrence;
 175     const u64 Integral = Occurrence == 0 ? 0 : AccumulatedTime / Occurrence;
 176     // Only keep single digit of fraction is enough and it enables easier layout
 177     // maintenance.
 178     const u64 Fraction =
 179         Occurrence == 0 ? 0
 180                         : ((AccumulatedTime % Occurrence) * 10) / Occurrence;
 181
 182     Str.append("%14" PRId64 ".%" PRId64 "(ns) %-11s", Integral, Fraction, " ");
 183
 184     for (u32 I = 0; I < ExtraIndent; ++I)
 185       Str.append("%s", "  ");
 186     Str.append("%s (%" PRId64 ")\n", Timers[HandleId].Name, Occurrence);
 187
 188     for (u32 I = 0; I < NumAllocatedTimers; ++I)
 189       if (Timers[I].Nesting == HandleId)
 190         printImpl(Str, I, ExtraIndent + 1);
 191   }
 192
 193   // Instead of maintaining pages for timer registration, a static buffer is
 194   // sufficient for most use cases in Scudo.
 195   static constexpr u32 MaxNumberOfTimers = 50;
 196   static constexpr u32 MaxLenOfTimerName = 50;
 197   static constexpr u32 DefaultPrintingInterval = 100;
 198
 199   struct Record {
 200     u64 AccumulatedTime = 0;
 201     u64 Occurrence = 0;
 202   };
 203
 204   struct TimerInfo {
 205     char Name[MaxLenOfTimerName + 1];
 206     u32 Nesting = MaxNumberOfTimers;
 207   };
 208
 209   HybridMutex Mutex;
 210   // The frequency of proactively dumping the timer statistics. For example, the
 211   // default setting is to dump the statistics every 100 reported events.
 212   u32 PrintingInterval GUARDED_BY(Mutex);
 213   u64 NumEventsReported GUARDED_BY(Mutex) = 0;
 214   u32 NumAllocatedTimers GUARDED_BY(Mutex) = 0;
 215   TimerInfo Timers[MaxNumberOfTimers] GUARDED_BY(Mutex);
 216   Record TimerRecords[MaxNumberOfTimers] GUARDED_BY(Mutex);
 217 };
 218
 219 } // namespace scudo
 220
 221 #endif // SCUDO_TIMING_H_