147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org/* 247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * Copyright 2013 The WebRTC Project Authors. All rights reserved. 347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * 447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * Use of this source code is governed by a BSD-style license 547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * that can be found in the LICENSE file in the root of the source 647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * tree. An additional intellectual property rights grant can be found 747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * in the file PATENTS. All contributing project authors may 847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org * be found in the AUTHORS file in the root of the source tree. 947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org */ 1047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 1147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org#include "webrtc/base/profiler.h" 1247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 1347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org#include <math.h> 1447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 1547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org#include "webrtc/base/timeutils.h" 1647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 1747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgnamespace { 1847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 1947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org// When written to an ostream, FormattedTime chooses an appropriate scale and 2047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org// suffix for a time value given in seconds. 2147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgclass FormattedTime { 2247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org public: 2347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org explicit FormattedTime(double t) : time_(t) {} 2447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org double time() const { return time_; } 2547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org private: 2647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org double time_; 2747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org}; 2847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 2947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgstd::ostream& operator<<(std::ostream& stream, const FormattedTime& time) { 3047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (time.time() < 1.0) { 3147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org stream << (time.time() * 1000.0) << "ms"; 3247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } else { 3347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org stream << time.time() << 's'; 3447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 3547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return stream; 3647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 3747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 3847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} // namespace 3947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 4047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgnamespace rtc { 4147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 4247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgProfilerEvent::ProfilerEvent() 4347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org : total_time_(0.0), 4447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org mean_(0.0), 4547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org sum_of_squared_differences_(0.0), 4647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org start_count_(0), 4747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org event_count_(0) { 4847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 4947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 5047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid ProfilerEvent::Start() { 5147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (start_count_ == 0) { 5247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org current_start_time_ = TimeNanos(); 5347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 5447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ++start_count_; 5547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 5647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 5747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid ProfilerEvent::Stop(uint64 stop_time) { 5847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org --start_count_; 5947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ASSERT(start_count_ >= 0); 6047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (start_count_ == 0) { 6147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org double elapsed = static_cast<double>(stop_time - current_start_time_) / 6247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org kNumNanosecsPerSec; 6347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org total_time_ += elapsed; 6447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (event_count_ == 0) { 6547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org minimum_ = maximum_ = elapsed; 6647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } else { 6747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org minimum_ = _min(minimum_, elapsed); 6847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org maximum_ = _max(maximum_, elapsed); 6947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 7047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org // Online variance and mean algorithm: http://en.wikipedia.org/wiki/ 7147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org // Algorithms_for_calculating_variance#Online_algorithm 7247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ++event_count_; 7347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org double delta = elapsed - mean_; 7447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org mean_ = mean_ + delta / event_count_; 7547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org sum_of_squared_differences_ += delta * (elapsed - mean_); 7647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 7747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 7847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 7947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid ProfilerEvent::Stop() { 8047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org Stop(TimeNanos()); 8147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 8247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 8347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgdouble ProfilerEvent::standard_deviation() const { 8447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (event_count_ <= 1) return 0.0; 8547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return sqrt(sum_of_squared_differences_ / (event_count_ - 1.0)); 8647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 8747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 8847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgProfiler* Profiler::Instance() { 8947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org LIBJINGLE_DEFINE_STATIC_LOCAL(Profiler, instance, ()); 9047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return &instance; 9147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 9247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 9347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid Profiler::StartEvent(const std::string& event_name) { 9447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org lock_.LockShared(); 9547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org EventMap::iterator it = events_.find(event_name); 9647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org bool needs_insert = (it == events_.end()); 9747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org lock_.UnlockShared(); 9847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 9947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (needs_insert) { 10047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org // Need an exclusive lock to modify the map. 10147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ExclusiveScope scope(&lock_); 10247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org it = events_.insert( 10347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org EventMap::value_type(event_name, ProfilerEvent())).first; 10447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 10547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 10647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org it->second.Start(); 10747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 10847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 10947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid Profiler::StopEvent(const std::string& event_name) { 11047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org // Get the time ASAP, then wait for the lock. 11147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org uint64 stop_time = TimeNanos(); 11247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org SharedScope scope(&lock_); 11347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org EventMap::iterator it = events_.find(event_name); 11447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (it != events_.end()) { 11547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org it->second.Stop(stop_time); 11647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 11747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 11847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 11947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid Profiler::ReportToLog(const char* file, int line, 12047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org LoggingSeverity severity_to_use, 12147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org const std::string& event_prefix) { 12247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (!LogMessage::Loggable(severity_to_use)) { 12347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return; 12447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 12547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 12647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org SharedScope scope(&lock_); 12747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 12847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org { // Output first line. 12947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org LogMessage msg(file, line, severity_to_use); 13047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org msg.stream() << "=== Profile report "; 13147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (event_prefix.empty()) { 13247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org msg.stream() << "(prefix: '" << event_prefix << "') "; 13347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 13447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org msg.stream() << "==="; 13547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 13647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org for (EventMap::const_iterator it = events_.begin(); 13747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org it != events_.end(); ++it) { 13847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (event_prefix.empty() || it->first.find(event_prefix) == 0) { 13947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org LogMessage(file, line, severity_to_use).stream() 14047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << it->first << " " << it->second; 14147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 14247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 14347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org LogMessage(file, line, severity_to_use).stream() 14447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << "=== End profile report ==="; 14547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 14647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 14747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgvoid Profiler::ReportAllToLog(const char* file, int line, 14847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org LoggingSeverity severity_to_use) { 14947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ReportToLog(file, line, severity_to_use, ""); 15047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 15147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 15247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgconst ProfilerEvent* Profiler::GetEvent(const std::string& event_name) const { 15347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org SharedScope scope(&lock_); 15447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org EventMap::const_iterator it = 15547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org events_.find(event_name); 15647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return (it == events_.end()) ? NULL : &it->second; 15747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 15847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 15947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgbool Profiler::Clear() { 16047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ExclusiveScope scope(&lock_); 16147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org bool result = true; 16247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org // Clear all events that aren't started. 16347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org EventMap::iterator it = events_.begin(); 16447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org while (it != events_.end()) { 16547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org if (it->second.is_started()) { 16647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org ++it; // Can't clear started events. 16747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org result = false; 16847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } else { 16947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org events_.erase(it++); 17047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 17147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org } 17247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return result; 17347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 17447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 17547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.orgstd::ostream& operator<<(std::ostream& stream, 17647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org const ProfilerEvent& profiler_event) { 17747be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org stream << "count=" << profiler_event.event_count() 17847be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << " total=" << FormattedTime(profiler_event.total_time()) 17947be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << " mean=" << FormattedTime(profiler_event.mean()) 18047be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << " min=" << FormattedTime(profiler_event.minimum()) 18147be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << " max=" << FormattedTime(profiler_event.maximum()) 18247be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org << " sd=" << profiler_event.standard_deviation(); 18347be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org return stream; 18447be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} 18547be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org 18647be73b8629244d6bb63a28198f97f040ce53d21henrike@webrtc.org} // namespace rtc 187