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
20namespace scudo {
21
22class TimingManager;
23
24// A simple timer for evaluating execution time of code snippets. It can be used
25// along with TimingManager or standalone.
26class Timer {
27public:
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
60protected:
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.
74class ScopedTimer : public Timer {
75public:
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.
85class TimingManager {
86public:
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(s1: Name, s2: Timers[I].Name, n: MaxLenOfTimerName) == 0)
100 return Timer(*this, I);
101 }
102
103 CHECK_LT(NumAllocatedTimers, MaxNumberOfTimers);
104 strncpy(dest: Timers[NumAllocatedTimers].Name, src: Name, n: 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
155private:
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(Format: "%-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, HandleId: 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(Format: "%14" PRId64 ".%" PRId64 "(ns) %-11s", Integral, Fraction, " ");
183
184 for (u32 I = 0; I < ExtraIndent; ++I)
185 Str.append(Format: "%s", " ");
186 Str.append(Format: "%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, HandleId: I, ExtraIndent: 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_
222

source code of compiler-rt/lib/scudo/standalone/timing.h