• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  * Copyright (C) 2011 The Android Open Source Project
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  *      http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 #ifndef ART_RUNTIME_BASE_TIMING_LOGGER_H_
18 #define ART_RUNTIME_BASE_TIMING_LOGGER_H_
19 
20 #include "base/locks.h"
21 #include "base/macros.h"
22 #include "base/time_utils.h"
23 
24 #include <memory>
25 #include <set>
26 #include <string>
27 #include <vector>
28 
29 namespace art {
30 class TimingLogger;
31 
32 class CumulativeLogger {
33  public:
34   explicit CumulativeLogger(const std::string& name);
35   ~CumulativeLogger();
36   void Start();
37   void End() REQUIRES(!GetLock());
38   void Reset() REQUIRES(!GetLock());
39   void Dump(std::ostream& os) const REQUIRES(!GetLock());
GetTotalNs()40   uint64_t GetTotalNs() const {
41     return GetTotalTime() * kAdjust;
42   }
43   // Allow the name to be modified, particularly when the cumulative logger is a field within a
44   // parent class that is unable to determine the "name" of a sub-class.
45   void SetName(const std::string& name) REQUIRES(!GetLock());
46   void AddLogger(const TimingLogger& logger) REQUIRES(!GetLock());
47   size_t GetIterations() const REQUIRES(!GetLock());
48 
49  private:
50   class CumulativeTime {
51    public:
CumulativeTime(const char * name,uint64_t time)52     CumulativeTime(const char* name, uint64_t time) : name_(name), time_(time) {}
Add(uint64_t time)53     void Add(uint64_t time) { time_ += time; }
Name()54     const char* Name() const { return name_; }
Sum()55     uint64_t Sum() const { return time_; }
56     // Compare addresses of names for sorting.
57     bool operator< (const CumulativeTime& ct) const {
58       return std::less<const char*>()(name_, ct.name_);
59     }
60 
61    private:
62     const char* name_;
63     uint64_t time_;
64   };
65 
66   void DumpAverages(std::ostream &os) const REQUIRES(GetLock());
67   void AddPair(const char* label, uint64_t delta_time) REQUIRES(GetLock());
GetTotalTime()68   uint64_t GetTotalTime() const {
69     return total_time_;
70   }
71 
GetLock()72   Mutex* GetLock() const {
73     return lock_.get();
74   }
75 
76   static constexpr uint64_t kAdjust = 1000;
77   // Use a vector to keep dirty memory to minimal number of pages. Using a
78   // hashtable would be performant, but could lead to more dirty pages. Also, we
79   // don't expect this vector to be too big.
80   std::vector<CumulativeTime> cumulative_timers_ GUARDED_BY(GetLock());
81   std::string name_;
82   const std::string lock_name_;
83   mutable std::unique_ptr<Mutex> lock_ DEFAULT_MUTEX_ACQUIRED_AFTER;
84   size_t iterations_ GUARDED_BY(GetLock());
85   uint64_t total_time_;
86 
87   DISALLOW_COPY_AND_ASSIGN(CumulativeLogger);
88 };
89 
90 // A timing logger that knows when a split starts for the purposes of logging tools, like systrace.
91 class TimingLogger {
92  public:
93   static constexpr size_t kIndexNotFound = static_cast<size_t>(-1);
94 
95   // Kind of timing we are going to do. We collect time at the nano second.
96   enum class TimingKind {
97     kMonotonic,
98     kThreadCpu,
99   };
100 
101   class Timing {
102    public:
Timing(TimingKind kind,const char * name)103     Timing(TimingKind kind, const char* name) : name_(name) {
104        switch (kind) {
105         case TimingKind::kMonotonic:
106           time_ = NanoTime();
107           break;
108         case TimingKind::kThreadCpu:
109           time_ = ThreadCpuNanoTime();
110           break;
111        }
112     }
IsStartTiming()113     bool IsStartTiming() const {
114       return !IsEndTiming();
115     }
IsEndTiming()116     bool IsEndTiming() const {
117       return name_ == nullptr;
118     }
GetTime()119     uint64_t GetTime() const {
120       return time_;
121     }
GetName()122     const char* GetName() const {
123       return name_;
124     }
125 
126    private:
127     uint64_t time_;
128     const char* name_;
129   };
130 
131   // Extra data that is only calculated when you call dump to prevent excess allocation.
132   class TimingData {
133    public:
134     TimingData() = default;
135     TimingData(TimingData&& other) noexcept = default;
136     TimingData& operator=(TimingData&& other) noexcept = default;
GetTotalTime(size_t idx)137     uint64_t GetTotalTime(size_t idx) {
138       return data_[idx].total_time;
139     }
GetExclusiveTime(size_t idx)140     uint64_t GetExclusiveTime(size_t idx) {
141       return data_[idx].exclusive_time;
142     }
143 
144    private:
145     // Each begin split has a total time and exclusive time. Exclusive time is total time - total
146     // time of children nodes.
147     struct CalculatedDataPoint {
CalculatedDataPointCalculatedDataPoint148       CalculatedDataPoint() : total_time(0), exclusive_time(0) {}
149       uint64_t total_time;
150       uint64_t exclusive_time;
151     };
152     std::vector<CalculatedDataPoint> data_;
153     friend class TimingLogger;
154   };
155 
156   TimingLogger(const char* name,
157                bool precise,
158                bool verbose,
159                TimingKind kind = TimingKind::kMonotonic);
160   ~TimingLogger();
161   // Verify that all open timings have related closed timings.
162   void Verify();
163   // Clears current timings and labels.
164   void Reset();
165   // Starts a timing.
166   void StartTiming(const char* new_split_label);
167   // Ends the current timing.
168   void EndTiming();
169   // End the current timing and start a new timing. Usage not recommended.
NewTiming(const char * new_split_label)170   void NewTiming(const char* new_split_label) {
171     EndTiming();
172     StartTiming(new_split_label);
173   }
174   // Returns the total duration of the timings (sum of total times).
175   uint64_t GetTotalNs() const;
176   // Find the index of a timing by name.
177   size_t FindTimingIndex(const char* name, size_t start_idx) const;
178   void Dump(std::ostream& os, const char* indent_string = "  ") const;
179 
180   // Scoped timing splits that can be nested and composed with the explicit split
181   // starts and ends.
182   class ScopedTiming {
183    public:
ScopedTiming(const char * label,TimingLogger * logger)184     ScopedTiming(const char* label, TimingLogger* logger) : logger_(logger) {
185       logger_->StartTiming(label);
186     }
~ScopedTiming()187     ~ScopedTiming() {
188       logger_->EndTiming();
189     }
190     // Closes the current timing and opens a new timing.
NewTiming(const char * label)191     void NewTiming(const char* label) {
192       logger_->NewTiming(label);
193     }
194 
195    private:
196     TimingLogger* const logger_;  // The timing logger which the scoped timing is associated with.
197     DISALLOW_COPY_AND_ASSIGN(ScopedTiming);
198   };
199 
200   // Return the time points of when each start / end timings start and finish.
GetTimings()201   const std::vector<Timing>& GetTimings() const {
202     return timings_;
203   }
204 
205   TimingData CalculateTimingData() const;
206 
207  protected:
208   // The name of the timing logger.
209   const char* const name_;
210   // Do we want to print the exactly recorded split (true) or round down to the time unit being
211   // used (false).
212   const bool precise_;
213   // Verbose logging.
214   const bool verbose_;
215   // The kind of timing we want.
216   const TimingKind kind_;
217   // Timing points that are either start or end points. For each starting point ret[i] = location
218   // of end split associated with i. If it is and end split ret[i] = i.
219   std::vector<Timing> timings_;
220 
221  private:
222   DISALLOW_COPY_AND_ASSIGN(TimingLogger);
223 };
224 
225 }  // namespace art
226 
227 #endif  // ART_RUNTIME_BASE_TIMING_LOGGER_H_
228