Home | History | Annotate | Download | only in base
      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/histogram.h"
     21 #include "base/macros.h"
     22 #include "base/mutex.h"
     23 
     24 #include <set>
     25 #include <string>
     26 #include <vector>
     27 
     28 namespace art {
     29 class TimingLogger;
     30 
     31 class CumulativeLogger {
     32  public:
     33   explicit CumulativeLogger(const std::string& name);
     34   ~CumulativeLogger();
     35   void Start();
     36   void End() LOCKS_EXCLUDED(lock_);
     37   void Reset() LOCKS_EXCLUDED(lock_);
     38   void Dump(std::ostream& os) const LOCKS_EXCLUDED(lock_);
     39   uint64_t GetTotalNs() const {
     40     return GetTotalTime() * kAdjust;
     41   }
     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.
     44   void SetName(const std::string& name) LOCKS_EXCLUDED(lock_);
     45   void AddLogger(const TimingLogger& logger) LOCKS_EXCLUDED(lock_);
     46   size_t GetIterations() const;
     47 
     48  private:
     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.
     59 
     60   void AddPair(const std::string &label, uint64_t delta_time)
     61       EXCLUSIVE_LOCKS_REQUIRED(lock_);
     62   void DumpHistogram(std::ostream &os) const EXCLUSIVE_LOCKS_REQUIRED(lock_);
     63   uint64_t GetTotalTime() const {
     64     return total_time_;
     65   }
     66   static const uint64_t kAdjust = 1000;
     67   std::set<Histogram<uint64_t>*, HistogramComparator> histograms_ GUARDED_BY(lock_);
     68   std::string name_;
     69   const std::string lock_name_;
     70   mutable Mutex lock_ DEFAULT_MUTEX_ACQUIRED_AFTER;
     71   size_t iterations_ GUARDED_BY(lock_);
     72   uint64_t total_time_;
     73 
     74   DISALLOW_COPY_AND_ASSIGN(CumulativeLogger);
     75 };
     76 
     77 // A timing logger that knows when a split starts for the purposes of logging tools, like systrace.
     78 class TimingLogger {
     79  public:
     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   };
    133 
    134   explicit TimingLogger(const char* name, bool precise, bool verbose);
    135   ~TimingLogger();
    136   // Verify that all open timings have related closed timings.
    137   void Verify();
    138   // Clears current timings and labels.
    139   void Reset();
    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).
    150   uint64_t GetTotalNs() const;
    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;
    154 
    155   // Scoped timing splits that can be nested and composed with the explicit split
    156   // starts and ends.
    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     }
    169 
    170    private:
    171     TimingLogger* const logger_;  // The timing logger which the scoped timing is associated with.
    172     DISALLOW_COPY_AND_ASSIGN(ScopedTiming);
    173   };
    174 
    175   // Return the time points of when each start / end timings start and finish.
    176   const std::vector<Timing>& GetTimings() const {
    177     return timings_;
    178   }
    179 
    180   TimingData CalculateTimingData() const;
    181 
    182  protected:
    183   // The name of the timing logger.
    184   const char* const name_;
    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_;
    188   // Verbose logging.
    189   const bool verbose_;
    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_;
    193 
    194  private:
    195   DISALLOW_COPY_AND_ASSIGN(TimingLogger);
    196 };
    197 
    198 }  // namespace art
    199 
    200 #endif  // ART_RUNTIME_BASE_TIMING_LOGGER_H_
    201