• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 // Copyright (c) 2018 Google LLC.
2 //
3 // Licensed under the Apache License, Version 2.0 (the "License");
4 // you may not use this file except in compliance with the License.
5 // You may obtain a copy of the License at
6 //
7 //     http://www.apache.org/licenses/LICENSE-2.0
8 //
9 // Unless required by applicable law or agreed to in writing, software
10 // distributed under the License is distributed on an "AS IS" BASIS,
11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 // See the License for the specific language governing permissions and
13 // limitations under the License.
14 
15 // Contains utils for getting resource utilization
16 
17 #ifndef SOURCE_UTIL_TIMER_H_
18 #define SOURCE_UTIL_TIMER_H_
19 
20 #if defined(SPIRV_TIMER_ENABLED)
21 
22 #include <sys/resource.h>
23 #include <cassert>
24 #include <iostream>
25 
26 // A macro to call spvtools::utils::PrintTimerDescription(std::ostream*, bool).
27 // The first argument must be given as std::ostream*. If it is NULL, the
28 // function does nothing. Otherwise, it prints resource types measured by Timer
29 // class. The second is optional and if it is true, the function also prints
30 // resource type fields related to memory. Otherwise, it does not print memory
31 // related fields. Its default is false. In usual, this must be placed before
32 // calling Timer::Report() to inform what those fields printed by
33 // Timer::Report() indicate (or spvtools::utils::PrintTimerDescription() must be
34 // used instead).
35 #define SPIRV_TIMER_DESCRIPTION(...) \
36   spvtools::utils::PrintTimerDescription(__VA_ARGS__)
37 
38 // Creates an object of ScopedTimer to measure the resource utilization for the
39 // scope surrounding it as the following example:
40 //
41 //   {   // <-- beginning of this scope
42 //
43 //     /* ... code out of interest ... */
44 //
45 //     SPIRV_TIMER_SCOPED(std::cout, tag);
46 //
47 //     /* ... lines of code that we want to know its resource usage ... */
48 //
49 //   }   // <-- end of this scope. The destructor of ScopedTimer prints tag and
50 //              the resource utilization to std::cout.
51 #define SPIRV_TIMER_SCOPED(...)                                         \
52   spvtools::utils::ScopedTimer<spvtools::utils::Timer> timer##__LINE__( \
53       __VA_ARGS__)
54 
55 namespace spvtools {
56 namespace utils {
57 
58 // Prints the description of resource types measured by Timer class. If |out| is
59 // NULL, it does nothing. Otherwise, it prints resource types. The second is
60 // optional and if it is true, the function also prints resource type fields
61 // related to memory. Its default is false. In usual, this must be placed before
62 // calling Timer::Report() to inform what those fields printed by
63 // Timer::Report() indicate.
64 void PrintTimerDescription(std::ostream*, bool = false);
65 
66 // Status of Timer. kGetrusageFailed means it failed in calling getrusage().
67 // kClockGettimeWalltimeFailed means it failed in getting wall time when calling
68 // clock_gettime(). kClockGettimeCPUtimeFailed means it failed in getting CPU
69 // time when calling clock_gettime().
70 enum UsageStatus {
71   kSucceeded = 0,
72   kGetrusageFailed = 1 << 0,
73   kClockGettimeWalltimeFailed = 1 << 1,
74   kClockGettimeCPUtimeFailed = 1 << 2,
75 };
76 
77 // Timer measures the resource utilization for a range of code. The resource
78 // utilization consists of CPU time (i.e., process time), WALL time (elapsed
79 // time), USR time, SYS time, RSS delta, and the delta of the number of page
80 // faults. RSS delta and the delta of the number of page faults are measured
81 // only when |measure_mem_usage| given to the constructor is true. This class
82 // should be used as the following example:
83 //
84 //   spvtools::utils::Timer timer(std::cout);
85 //   timer.Start();       // <-- set |usage_before_|, |wall_before_|,
86 //                               and |cpu_before_|
87 //
88 //   /* ... lines of code that we want to know its resource usage ... */
89 //
90 //   timer.Stop();        // <-- set |cpu_after_|, |wall_after_|, and
91 //                               |usage_after_|
92 //   timer.Report(tag);   // <-- print tag and the resource utilization to
93 //                               std::cout.
94 class Timer {
95  public:
96   Timer(std::ostream* out, bool measure_mem_usage = false)
report_stream_(out)97       : report_stream_(out),
98         usage_status_(kSucceeded),
99         measure_mem_usage_(measure_mem_usage) {}
100 
101   // Sets |usage_before_|, |wall_before_|, and |cpu_before_| as results of
102   // getrusage(), clock_gettime() for the wall time, and clock_gettime() for the
103   // CPU time respectively. Note that this method erases all previous state of
104   // |usage_before_|, |wall_before_|, |cpu_before_|.
105   virtual void Start();
106 
107   // Sets |cpu_after_|, |wall_after_|, and |usage_after_| as results of
108   // clock_gettime() for the wall time, and clock_gettime() for the CPU time,
109   // getrusage() respectively. Note that this method erases all previous state
110   // of |cpu_after_|, |wall_after_|, |usage_after_|.
111   virtual void Stop();
112 
113   // If |report_stream_| is NULL, it does nothing. Otherwise, it prints the
114   // resource utilization (i.e., CPU/WALL/USR/SYS time, RSS delta) between the
115   // time of calling Timer::Start() and the time of calling Timer::Stop(). If we
116   // cannot get a resource usage because of failures, it prints "Failed" instead
117   // for the resource.
118   void Report(const char* tag);
119 
120   // Returns the measured CPU Time (i.e., process time) for a range of code
121   // execution. If kClockGettimeCPUtimeFailed is set by the failure of calling
122   // clock_gettime(), it returns -1.
CPUTime()123   virtual double CPUTime() {
124     if (usage_status_ & kClockGettimeCPUtimeFailed) return -1;
125     return TimeDifference(cpu_before_, cpu_after_);
126   }
127 
128   // Returns the measured Wall Time (i.e., elapsed time) for a range of code
129   // execution. If kClockGettimeWalltimeFailed is set by the failure of
130   // calling clock_gettime(), it returns -1.
WallTime()131   virtual double WallTime() {
132     if (usage_status_ & kClockGettimeWalltimeFailed) return -1;
133     return TimeDifference(wall_before_, wall_after_);
134   }
135 
136   // Returns the measured USR Time for a range of code execution. If
137   // kGetrusageFailed is set because of the failure of calling getrusage(), it
138   // returns -1.
UserTime()139   virtual double UserTime() {
140     if (usage_status_ & kGetrusageFailed) return -1;
141     return TimeDifference(usage_before_.ru_utime, usage_after_.ru_utime);
142   }
143 
144   // Returns the measured SYS Time for a range of code execution. If
145   // kGetrusageFailed is set because of the failure of calling getrusage(), it
146   // returns -1.
SystemTime()147   virtual double SystemTime() {
148     if (usage_status_ & kGetrusageFailed) return -1;
149     return TimeDifference(usage_before_.ru_stime, usage_after_.ru_stime);
150   }
151 
152   // Returns the measured RSS delta for a range of code execution. If
153   // kGetrusageFailed is set because of the failure of calling getrusage(), it
154   // returns -1.
RSS()155   virtual long RSS() const {
156     if (usage_status_ & kGetrusageFailed) return -1;
157     return usage_after_.ru_maxrss - usage_before_.ru_maxrss;
158   }
159 
160   // Returns the measured the delta of the number of page faults for a range of
161   // code execution. If kGetrusageFailed is set because of the failure of
162   // calling getrusage(), it returns -1.
PageFault()163   virtual long PageFault() const {
164     if (usage_status_ & kGetrusageFailed) return -1;
165     return (usage_after_.ru_minflt - usage_before_.ru_minflt) +
166            (usage_after_.ru_majflt - usage_before_.ru_majflt);
167   }
168 
~Timer()169   virtual ~Timer() {}
170 
171  private:
172   // Returns the time gap between |from| and |to| in seconds.
TimeDifference(const timeval & from,const timeval & to)173   static double TimeDifference(const timeval& from, const timeval& to) {
174     assert((to.tv_sec > from.tv_sec) ||
175            (to.tv_sec == from.tv_sec && to.tv_usec >= from.tv_usec));
176     return static_cast<double>(to.tv_sec - from.tv_sec) +
177            static_cast<double>(to.tv_usec - from.tv_usec) * .000001;
178   }
179 
180   // Returns the time gap between |from| and |to| in seconds.
TimeDifference(const timespec & from,const timespec & to)181   static double TimeDifference(const timespec& from, const timespec& to) {
182     assert((to.tv_sec > from.tv_sec) ||
183            (to.tv_sec == from.tv_sec && to.tv_nsec >= from.tv_nsec));
184     return static_cast<double>(to.tv_sec - from.tv_sec) +
185            static_cast<double>(to.tv_nsec - from.tv_nsec) * .000000001;
186   }
187 
188   // Output stream to print out the resource utilization. If it is NULL,
189   // Report() does nothing.
190   std::ostream* report_stream_;
191 
192   // Status to stop measurement if a system call returns an error.
193   unsigned usage_status_;
194 
195   // Variable to save the result of clock_gettime(CLOCK_PROCESS_CPUTIME_ID) when
196   // Timer::Start() is called. It is used as the base status of CPU time.
197   timespec cpu_before_;
198 
199   // Variable to save the result of clock_gettime(CLOCK_MONOTONIC) when
200   // Timer::Start() is called. It is used as the base status of WALL time.
201   timespec wall_before_;
202 
203   // Variable to save the result of getrusage() when Timer::Start() is called.
204   // It is used as the base status of USR time, SYS time, and RSS.
205   rusage usage_before_;
206 
207   // Variable to save the result of clock_gettime(CLOCK_PROCESS_CPUTIME_ID) when
208   // Timer::Stop() is called. It is used as the last status of CPU time. The
209   // resouce usage is measured by subtracting |cpu_before_| from it.
210   timespec cpu_after_;
211 
212   // Variable to save the result of clock_gettime(CLOCK_MONOTONIC) when
213   // Timer::Stop() is called. It is used as the last status of WALL time. The
214   // resouce usage is measured by subtracting |wall_before_| from it.
215   timespec wall_after_;
216 
217   // Variable to save the result of getrusage() when Timer::Stop() is called. It
218   // is used as the last status of USR time, SYS time, and RSS. Those resouce
219   // usages are measured by subtracting |usage_before_| from it.
220   rusage usage_after_;
221 
222   // If true, Timer reports the memory usage information too. Otherwise, Timer
223   // reports only USR time, WALL time, SYS time.
224   bool measure_mem_usage_;
225 };
226 
227 // The purpose of ScopedTimer is to measure the resource utilization for a
228 // scope. Simply creating a local variable of ScopedTimer will call
229 // Timer::Start() and it calls Timer::Stop() and Timer::Report() at the end of
230 // the scope by its destructor. When we use this class, we must choose the
231 // proper Timer class (for class TimerType template) in advance. This class
232 // should be used as the following example:
233 //
234 //   {   // <-- beginning of this scope
235 //
236 //     /* ... code out of interest ... */
237 //
238 //     spvtools::utils::ScopedTimer<spvtools::utils::Timer>
239 //     scopedtimer(std::cout, tag);
240 //
241 //     /* ... lines of code that we want to know its resource usage ... */
242 //
243 //   }   // <-- end of this scope. The destructor of ScopedTimer prints tag and
244 //              the resource utilization to std::cout.
245 //
246 // The template<class TimerType> is used to choose a Timer class. Currently,
247 // only options for the Timer class are Timer and MockTimer in the unit test.
248 template <class TimerType>
249 class ScopedTimer {
250  public:
251   ScopedTimer(std::ostream* out, const char* tag,
252               bool measure_mem_usage = false)
timer(new TimerType (out,measure_mem_usage))253       : timer(new TimerType(out, measure_mem_usage)), tag_(tag) {
254     timer->Start();
255   }
256 
257   // At the end of the scope surrounding the instance of this class, this
258   // destructor saves the last status of resource usage and reports it.
~ScopedTimer()259   virtual ~ScopedTimer() {
260     timer->Stop();
261     timer->Report(tag_);
262     delete timer;
263   }
264 
265  private:
266   // Actual timer that measures the resource utilization. It must be an instance
267   // of Timer class if there is no special reason to use other class.
268   TimerType* timer;
269 
270   // A tag that will be printed in front of the trace reported by Timer class.
271   const char* tag_;
272 };
273 
274 // CumulativeTimer is the same as Timer class, but it supports a cumulative
275 // measurement as the following example:
276 //
277 //   CumulativeTimer *ctimer = new CumulativeTimer(std::cout);
278 //   ctimer->Start();
279 //
280 //   /* ... lines of code that we want to know its resource usage ... */
281 //
282 //   ctimer->Stop();
283 //
284 //   /* ... code out of interest ... */
285 //
286 //   ctimer->Start();
287 //
288 //   /* ... lines of code that we want to know its resource usage ... */
289 //
290 //   ctimer->Stop();
291 //   ctimer->Report(tag);
292 //   delete ctimer;
293 //
294 class CumulativeTimer : public Timer {
295  public:
296   CumulativeTimer(std::ostream* out, bool measure_mem_usage = false)
Timer(out,measure_mem_usage)297       : Timer(out, measure_mem_usage),
298         cpu_time_(0),
299         wall_time_(0),
300         usr_time_(0),
301         sys_time_(0),
302         rss_(0),
303         pgfaults_(0) {}
304 
305   // If we cannot get a resource usage because of failures, it sets -1 for the
306   // resource usage.
Stop()307   void Stop() override {
308     Timer::Stop();
309 
310     if (cpu_time_ >= 0 && Timer::CPUTime() >= 0)
311       cpu_time_ += Timer::CPUTime();
312     else
313       cpu_time_ = -1;
314 
315     if (wall_time_ >= 0 && Timer::WallTime() >= 0)
316       wall_time_ += Timer::WallTime();
317     else
318       wall_time_ = -1;
319 
320     if (usr_time_ >= 0 && Timer::UserTime() >= 0)
321       usr_time_ += Timer::UserTime();
322     else
323       usr_time_ = -1;
324 
325     if (sys_time_ >= 0 && Timer::SystemTime() >= 0)
326       sys_time_ += Timer::SystemTime();
327     else
328       sys_time_ = -1;
329 
330     if (rss_ >= 0 && Timer::RSS() >= 0)
331       rss_ += Timer::RSS();
332     else
333       rss_ = -1;
334 
335     if (pgfaults_ >= 0 && Timer::PageFault() >= 0)
336       pgfaults_ += Timer::PageFault();
337     else
338       pgfaults_ = -1;
339   }
340 
341   // Returns the cumulative CPU Time (i.e., process time) for a range of code
342   // execution.
CPUTime()343   double CPUTime() override { return cpu_time_; }
344 
345   // Returns the cumulative Wall Time (i.e., elapsed time) for a range of code
346   // execution.
WallTime()347   double WallTime() override { return wall_time_; }
348 
349   // Returns the cumulative USR Time for a range of code execution.
UserTime()350   double UserTime() override { return usr_time_; }
351 
352   // Returns the cumulative SYS Time for a range of code execution.
SystemTime()353   double SystemTime() override { return sys_time_; }
354 
355   // Returns the cumulative RSS delta for a range of code execution.
RSS()356   long RSS() const override { return rss_; }
357 
358   // Returns the cumulative delta of number of page faults for a range of code
359   // execution.
PageFault()360   long PageFault() const override { return pgfaults_; }
361 
362  private:
363   // Variable to save the cumulative CPU time (i.e., process time).
364   double cpu_time_;
365 
366   // Variable to save the cumulative wall time (i.e., elapsed time).
367   double wall_time_;
368 
369   // Variable to save the cumulative user time.
370   double usr_time_;
371 
372   // Variable to save the cumulative system time.
373   double sys_time_;
374 
375   // Variable to save the cumulative RSS delta.
376   long rss_;
377 
378   // Variable to save the cumulative delta of the number of page faults.
379   long pgfaults_;
380 };
381 
382 }  // namespace utils
383 }  // namespace spvtools
384 
385 #else  // defined(SPIRV_TIMER_ENABLED)
386 
387 #define SPIRV_TIMER_DESCRIPTION(...)
388 #define SPIRV_TIMER_SCOPED(...)
389 
390 #endif  // defined(SPIRV_TIMER_ENABLED)
391 
392 #endif  // SOURCE_UTIL_TIMER_H_
393