Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 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 | |
Brian Carlstrom | fc0e321 | 2013-07-17 14:40:12 -0700 | [diff] [blame] | 17 | #ifndef ART_RUNTIME_BASE_TIMING_LOGGER_H_ |
| 18 | #define ART_RUNTIME_BASE_TIMING_LOGGER_H_ |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 19 | |
| 20 | #include "base/histogram.h" |
| 21 | #include "base/macros.h" |
| 22 | #include "base/mutex.h" |
| 23 | |
Mathieu Chartier | 19b0a91 | 2013-11-20 14:07:54 -0800 | [diff] [blame] | 24 | #include <set> |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 25 | #include <string> |
| 26 | #include <vector> |
| 27 | |
| 28 | namespace art { |
Ian Rogers | 5fe9af7 | 2013-11-14 00:17:20 -0800 | [diff] [blame] | 29 | class TimingLogger; |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 30 | |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 31 | class CumulativeLogger { |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 32 | public: |
Ian Rogers | 4535705 | 2013-04-18 20:49:43 -0700 | [diff] [blame] | 33 | explicit CumulativeLogger(const std::string& name); |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 34 | ~CumulativeLogger(); |
| 35 | void Start(); |
Mathieu Chartier | c528dba | 2013-11-26 12:00:11 -0800 | [diff] [blame] | 36 | void End() LOCKS_EXCLUDED(lock_); |
| 37 | void Reset() LOCKS_EXCLUDED(lock_); |
Mathieu Chartier | afe4998 | 2014-03-27 10:55:04 -0700 | [diff] [blame] | 38 | void Dump(std::ostream& os) const LOCKS_EXCLUDED(lock_); |
| 39 | uint64_t GetTotalNs() const { |
| 40 | return GetTotalTime() * kAdjust; |
| 41 | } |
Ian Rogers | 4535705 | 2013-04-18 20:49:43 -0700 | [diff] [blame] | 42 | // Allow the name to be modified, particularly when the cumulative logger is a field within a |
| 43 | // parent class that is unable to determine the "name" of a sub-class. |
Mathieu Chartier | c528dba | 2013-11-26 12:00:11 -0800 | [diff] [blame] | 44 | void SetName(const std::string& name) LOCKS_EXCLUDED(lock_); |
Ian Rogers | 5fe9af7 | 2013-11-14 00:17:20 -0800 | [diff] [blame] | 45 | void AddLogger(const TimingLogger& logger) LOCKS_EXCLUDED(lock_); |
Mathieu Chartier | 590fee9 | 2013-09-13 13:46:47 -0700 | [diff] [blame] | 46 | size_t GetIterations() const; |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 47 | |
| 48 | private: |
Mathieu Chartier | 19b0a91 | 2013-11-20 14:07:54 -0800 | [diff] [blame] | 49 | class HistogramComparator { |
| 50 | public: |
| 51 | bool operator()(const Histogram<uint64_t>* a, const Histogram<uint64_t>* b) const { |
| 52 | return a->Name() < b->Name(); |
| 53 | } |
| 54 | }; |
| 55 | |
| 56 | static constexpr size_t kLowMemoryBucketCount = 16; |
| 57 | static constexpr size_t kDefaultBucketCount = 100; |
| 58 | static constexpr size_t kInitialBucketSize = 50; // 50 microseconds. |
Anwar Ghuloum | 67f9941 | 2013-08-12 14:19:48 -0700 | [diff] [blame] | 59 | |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 60 | void AddPair(const std::string &label, uint64_t delta_time) |
| 61 | EXCLUSIVE_LOCKS_REQUIRED(lock_); |
Mathieu Chartier | afe4998 | 2014-03-27 10:55:04 -0700 | [diff] [blame] | 62 | void DumpHistogram(std::ostream &os) const EXCLUSIVE_LOCKS_REQUIRED(lock_); |
| 63 | uint64_t GetTotalTime() const { |
| 64 | return total_time_; |
| 65 | } |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 66 | static const uint64_t kAdjust = 1000; |
Mathieu Chartier | 19b0a91 | 2013-11-20 14:07:54 -0800 | [diff] [blame] | 67 | std::set<Histogram<uint64_t>*, HistogramComparator> histograms_ GUARDED_BY(lock_); |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 68 | std::string name_; |
Ian Rogers | 4535705 | 2013-04-18 20:49:43 -0700 | [diff] [blame] | 69 | const std::string lock_name_; |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 70 | mutable Mutex lock_ DEFAULT_MUTEX_ACQUIRED_AFTER; |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 71 | size_t iterations_ GUARDED_BY(lock_); |
Mathieu Chartier | afe4998 | 2014-03-27 10:55:04 -0700 | [diff] [blame] | 72 | uint64_t total_time_; |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 73 | |
| 74 | DISALLOW_COPY_AND_ASSIGN(CumulativeLogger); |
| 75 | }; |
| 76 | |
Anwar Ghuloum | 4446ab9 | 2013-08-09 21:17:25 -0700 | [diff] [blame] | 77 | // A timing logger that knows when a split starts for the purposes of logging tools, like systrace. |
Anwar Ghuloum | 6f28d91 | 2013-07-24 15:02:53 -0700 | [diff] [blame] | 78 | class TimingLogger { |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 79 | public: |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 80 | static constexpr size_t kIndexNotFound = static_cast<size_t>(-1); |
| 81 | |
| 82 | class Timing { |
| 83 | public: |
| 84 | Timing(uint64_t time, const char* name) : time_(time), name_(name) { |
| 85 | } |
| 86 | bool IsStartTiming() const { |
| 87 | return !IsEndTiming(); |
| 88 | } |
| 89 | bool IsEndTiming() const { |
| 90 | return name_ == nullptr; |
| 91 | } |
| 92 | uint64_t GetTime() const { |
| 93 | return time_; |
| 94 | } |
| 95 | const char* GetName() const { |
| 96 | return name_; |
| 97 | } |
| 98 | |
| 99 | private: |
| 100 | uint64_t time_; |
| 101 | const char* name_; |
| 102 | }; |
| 103 | |
| 104 | // Extra data that is only calculated when you call dump to prevent excess allocation. |
| 105 | class TimingData { |
| 106 | public: |
| 107 | TimingData() = default; |
| 108 | TimingData(TimingData&& other) { |
| 109 | std::swap(data_, other.data_); |
| 110 | } |
| 111 | TimingData& operator=(TimingData&& other) { |
| 112 | std::swap(data_, other.data_); |
| 113 | return *this; |
| 114 | } |
| 115 | uint64_t GetTotalTime(size_t idx) { |
| 116 | return data_[idx].total_time; |
| 117 | } |
| 118 | uint64_t GetExclusiveTime(size_t idx) { |
| 119 | return data_[idx].exclusive_time; |
| 120 | } |
| 121 | |
| 122 | private: |
| 123 | // Each begin split has a total time and exclusive time. Exclusive time is total time - total |
| 124 | // time of children nodes. |
| 125 | struct CalculatedDataPoint { |
| 126 | CalculatedDataPoint() : total_time(0), exclusive_time(0) {} |
| 127 | uint64_t total_time; |
| 128 | uint64_t exclusive_time; |
| 129 | }; |
| 130 | std::vector<CalculatedDataPoint> data_; |
| 131 | friend class TimingLogger; |
| 132 | }; |
Anwar Ghuloum | 4446ab9 | 2013-08-09 21:17:25 -0700 | [diff] [blame] | 133 | |
Anwar Ghuloum | 6f28d91 | 2013-07-24 15:02:53 -0700 | [diff] [blame] | 134 | explicit TimingLogger(const char* name, bool precise, bool verbose); |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 135 | ~TimingLogger(); |
| 136 | // Verify that all open timings have related closed timings. |
| 137 | void Verify(); |
| 138 | // Clears current timings and labels. |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 139 | void Reset(); |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 140 | // Starts a timing. |
| 141 | void StartTiming(const char* new_split_label); |
| 142 | // Ends the current timing. |
| 143 | void EndTiming(); |
| 144 | // End the current timing and start a new timing. Usage not recommended. |
| 145 | void NewTiming(const char* new_split_label) { |
| 146 | EndTiming(); |
| 147 | StartTiming(new_split_label); |
| 148 | } |
| 149 | // Returns the total duration of the timings (sum of total times). |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 150 | uint64_t GetTotalNs() const; |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 151 | // Find the index of a timing by name. |
| 152 | size_t FindTimingIndex(const char* name, size_t start_idx) const; |
| 153 | void Dump(std::ostream& os, const char* indent_string = " ") const; |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 154 | |
Anwar Ghuloum | 4446ab9 | 2013-08-09 21:17:25 -0700 | [diff] [blame] | 155 | // Scoped timing splits that can be nested and composed with the explicit split |
| 156 | // starts and ends. |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 157 | class ScopedTiming { |
| 158 | public: |
| 159 | explicit ScopedTiming(const char* label, TimingLogger* logger) : logger_(logger) { |
| 160 | logger_->StartTiming(label); |
| 161 | } |
| 162 | ~ScopedTiming() { |
| 163 | logger_->EndTiming(); |
| 164 | } |
| 165 | // Closes the current timing and opens a new timing. |
| 166 | void NewTiming(const char* label) { |
| 167 | logger_->NewTiming(label); |
| 168 | } |
Anwar Ghuloum | 4446ab9 | 2013-08-09 21:17:25 -0700 | [diff] [blame] | 169 | |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 170 | private: |
| 171 | TimingLogger* const logger_; // The timing logger which the scoped timing is associated with. |
| 172 | DISALLOW_COPY_AND_ASSIGN(ScopedTiming); |
Anwar Ghuloum | 4446ab9 | 2013-08-09 21:17:25 -0700 | [diff] [blame] | 173 | }; |
| 174 | |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 175 | // Return the time points of when each start / end timings start and finish. |
| 176 | const std::vector<Timing>& GetTimings() const { |
| 177 | return timings_; |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 178 | } |
| 179 | |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 180 | TimingData CalculateTimingData() const; |
| 181 | |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 182 | protected: |
| 183 | // The name of the timing logger. |
Ian Rogers | 5fe9af7 | 2013-11-14 00:17:20 -0800 | [diff] [blame] | 184 | const char* const name_; |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 185 | // Do we want to print the exactly recorded split (true) or round down to the time unit being |
| 186 | // used (false). |
| 187 | const bool precise_; |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 188 | // Verbose logging. |
| 189 | const bool verbose_; |
Mathieu Chartier | f5997b4 | 2014-06-20 10:37:54 -0700 | [diff] [blame] | 190 | // Timing points that are either start or end points. For each starting point ret[i] = location |
| 191 | // of end split associated with i. If it is and end split ret[i] = i. |
| 192 | std::vector<Timing> timings_; |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 193 | |
| 194 | private: |
Anwar Ghuloum | 6f28d91 | 2013-07-24 15:02:53 -0700 | [diff] [blame] | 195 | DISALLOW_COPY_AND_ASSIGN(TimingLogger); |
Ian Rogers | 1d54e73 | 2013-05-02 21:10:01 -0700 | [diff] [blame] | 196 | }; |
| 197 | |
Sameer Abu Asal | a843954 | 2013-02-14 16:06:42 -0800 | [diff] [blame] | 198 | } // namespace art |
| 199 | |
Brian Carlstrom | fc0e321 | 2013-07-17 14:40:12 -0700 | [diff] [blame] | 200 | #endif // ART_RUNTIME_BASE_TIMING_LOGGER_H_ |