diff options
Diffstat (limited to 'chrome/browser/jankometer.cc')
| -rw-r--r-- | chrome/browser/jankometer.cc | 285 |
1 files changed, 189 insertions, 96 deletions
diff --git a/chrome/browser/jankometer.cc b/chrome/browser/jankometer.cc index 97816ad..d4a70a2 100644 --- a/chrome/browser/jankometer.cc +++ b/chrome/browser/jankometer.cc @@ -81,80 +81,187 @@ class JankWatchdog : public Watchdog { DISALLOW_COPY_AND_ASSIGN(JankWatchdog); }; +class JankObserverHelper { + public: + JankObserverHelper(const std::string& thread_name, + const TimeDelta& excessive_duration, + bool watchdog_enable); + ~JankObserverHelper(); + + void StartProcessingTimers(const TimeDelta& queueing_time); + void EndProcessingTimers(); + + private: + const TimeDelta max_message_delay_; + + // Time at which the current message processing began. + TimeTicks begin_process_message_; + + // Time the current message spent in the queue -- delta between message + // construction time and message processing time. + TimeDelta queueing_time_; + + // Counters for the two types of jank we measure. + StatsCounter slow_processing_counter_; // Messages with long processing time. + StatsCounter queueing_delay_counter_; // Messages with long queueing delay. + scoped_refptr<Histogram> process_times_; // Time spent processing task. + scoped_refptr<Histogram> total_times_; // Total queueing plus processing. + JankWatchdog total_time_watchdog_; // Watching for excessive total_time. + + DISALLOW_COPY_AND_ASSIGN(JankObserverHelper); +}; + +JankObserverHelper::JankObserverHelper( + const std::string& thread_name, + const TimeDelta& excessive_duration, + bool watchdog_enable) + : max_message_delay_(excessive_duration), + slow_processing_counter_(std::string("Chrome.SlowMsg") + thread_name), + queueing_delay_counter_(std::string("Chrome.DelayMsg") + thread_name), + total_time_watchdog_(excessive_duration, thread_name, watchdog_enable) { + process_times_ = Histogram::FactoryGet( + std::string("Chrome.ProcMsgL ") + thread_name, + 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); + total_times_ = Histogram::FactoryGet( + std::string("Chrome.TotalMsgL ") + thread_name, + 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); +} + +JankObserverHelper::~JankObserverHelper() {} + +// Called when a message has just begun processing, initializes +// per-message variables and timers. +void JankObserverHelper::StartProcessingTimers(const TimeDelta& queueing_time) { + begin_process_message_ = TimeTicks::Now(); + queueing_time_ = queueing_time; + + // Simulate arming when the message entered the queue. + total_time_watchdog_.ArmSomeTimeDeltaAgo(queueing_time_); + if (queueing_time_ > max_message_delay_) { + // Message is too delayed. + queueing_delay_counter_.Increment(); +#if defined(OS_WIN) + if (kPlaySounds) + MessageBeep(MB_ICONASTERISK); +#endif + } +} + +// Called when a message has just finished processing, finalizes +// per-message variables and timers. +void JankObserverHelper::EndProcessingTimers() { + total_time_watchdog_.Disarm(); + TimeTicks now = TimeTicks::Now(); + if (begin_process_message_ != TimeTicks()) { + TimeDelta processing_time = now - begin_process_message_; + process_times_->AddTime(processing_time); + total_times_->AddTime(queueing_time_ + processing_time); + } + if (now - begin_process_message_ > + TimeDelta::FromMilliseconds(kMaxMessageProcessingMs)) { + // Message took too long to process. + slow_processing_counter_.Increment(); +#if defined(OS_WIN) + if (kPlaySounds) + MessageBeep(MB_ICONHAND); +#endif + } + + // Reset message specific times. + begin_process_message_ = base::TimeTicks(); + queueing_time_ = base::TimeDelta(); +} + //------------------------------------------------------------------------------ -class JankObserver : public base::RefCountedThreadSafe<JankObserver>, - public MessageLoopForUI::Observer { +class IOJankObserver : public base::RefCountedThreadSafe<IOJankObserver>, + public MessageLoopForIO::IOObserver, + public MessageLoop::TaskObserver { public: - JankObserver(const char* thread_name, - const TimeDelta& excessive_duration, - bool watchdog_enable) - : MaxMessageDelay_(excessive_duration), - slow_processing_counter_(std::string("Chrome.SlowMsg") + thread_name), - queueing_delay_counter_(std::string("Chrome.DelayMsg") + thread_name), - total_time_watchdog_(excessive_duration, thread_name, watchdog_enable) { - process_times_ = Histogram::FactoryGet( - std::string("Chrome.ProcMsgL ") + thread_name, - 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); - total_times_ = Histogram::FactoryGet( - std::string("Chrome.TotalMsgL ") + thread_name, - 1, 3600000, 50, Histogram::kUmaTargetedHistogramFlag); + IOJankObserver(const char* thread_name, + TimeDelta excessive_duration, + bool watchdog_enable) + : helper_(thread_name, excessive_duration, watchdog_enable) {} + + ~IOJankObserver() {} + + // Attaches the observer to the current thread's message loop. You can only + // attach to the current thread, so this function can be invoked on another + // thread to attach it. + void AttachToCurrentThread() { + MessageLoop::current()->AddTaskObserver(this); + MessageLoopForIO::current()->AddIOObserver(this); + } + + // Detaches the observer to the current thread's message loop. + void DetachFromCurrentThread() { + MessageLoopForIO::current()->RemoveIOObserver(this); + MessageLoop::current()->RemoveTaskObserver(this); } + virtual void WillProcessIOEvent() { + helper_.StartProcessingTimers(base::TimeDelta()); + } + + virtual void DidProcessIOEvent() { + helper_.EndProcessingTimers(); + } + + virtual void WillProcessTask(base::TimeTicks birth_time) { + base::TimeTicks now = base::TimeTicks::Now(); + const base::TimeDelta queueing_time = now - birth_time; + helper_.StartProcessingTimers(queueing_time); + } + + virtual void DidProcessTask() { + helper_.EndProcessingTimers(); + } + + private: + friend class base::RefCountedThreadSafe<IOJankObserver>; + + JankObserverHelper helper_; + + DISALLOW_COPY_AND_ASSIGN(IOJankObserver); +}; + +//------------------------------------------------------------------------------ +class UIJankObserver : public base::RefCountedThreadSafe<UIJankObserver>, + public MessageLoop::TaskObserver, + public MessageLoopForUI::Observer { + public: + UIJankObserver(const char* thread_name, + TimeDelta excessive_duration, + bool watchdog_enable) + : helper_(thread_name, excessive_duration, watchdog_enable) {} + // Attaches the observer to the current thread's message loop. You can only // attach to the current thread, so this function can be invoked on another // thread to attach it. void AttachToCurrentThread() { - // TODO(darin): support monitoring jankiness on non-UI threads! - if (MessageLoop::current()->type() == MessageLoop::TYPE_UI) - MessageLoopForUI::current()->AddObserver(this); + DCHECK_EQ(MessageLoop::current()->type(), MessageLoop::TYPE_UI); + MessageLoopForUI::current()->AddObserver(this); + MessageLoop::current()->AddTaskObserver(this); } // Detaches the observer to the current thread's message loop. void DetachFromCurrentThread() { - if (MessageLoop::current()->type() == MessageLoop::TYPE_UI) - MessageLoopForUI::current()->RemoveObserver(this); + DCHECK_EQ(MessageLoop::current()->type(), MessageLoop::TYPE_UI); + MessageLoop::current()->RemoveTaskObserver(this); + MessageLoopForUI::current()->RemoveObserver(this); } - // Called when a message has just begun processing, initializes - // per-message variables and timers. - void StartProcessingTimers() { - // Simulate arming when the message entered the queue. - total_time_watchdog_.ArmSomeTimeDeltaAgo(queueing_time_); - if (queueing_time_ > MaxMessageDelay_) { - // Message is too delayed. - queueing_delay_counter_.Increment(); -#if defined(OS_WIN) - if (kPlaySounds) - MessageBeep(MB_ICONASTERISK); -#endif - } + virtual void WillProcessTask(base::TimeTicks birth_time) { + base::TimeTicks now = base::TimeTicks::Now(); + const base::TimeDelta queueing_time = now - birth_time; + helper_.StartProcessingTimers(queueing_time); } - // Called when a message has just finished processing, finalizes - // per-message variables and timers. - void EndProcessingTimers() { - total_time_watchdog_.Disarm(); - TimeTicks now = TimeTicks::Now(); - if (begin_process_message_ != TimeTicks()) { - TimeDelta processing_time = now - begin_process_message_; - process_times_->AddTime(processing_time); - total_times_->AddTime(queueing_time_ + processing_time); - } - if (now - begin_process_message_ > - TimeDelta::FromMilliseconds(kMaxMessageProcessingMs)) { - // Message took too long to process. - slow_processing_counter_.Increment(); -#if defined(OS_WIN) - if (kPlaySounds) - MessageBeep(MB_ICONHAND); -#endif - } + virtual void DidProcessTask() { + helper_.EndProcessingTimers(); } #if defined(OS_WIN) virtual void WillProcessMessage(const MSG& msg) { - begin_process_message_ = TimeTicks::Now(); - // GetMessageTime returns a LONG (signed 32-bit) and GetTickCount returns // a DWORD (unsigned 32-bit). They both wrap around when the time is longer // than they can hold. I'm not sure if GetMessageTime wraps around to 0, @@ -166,58 +273,43 @@ class JankObserver : public base::RefCountedThreadSafe<JankObserver>, // to straddle the wraparound point, it will still be OK. DWORD cur_message_issue_time = static_cast<DWORD>(msg.time); DWORD cur_time = GetTickCount(); - queueing_time_ = + base::TimeDelta queueing_time = base::TimeDelta::FromMilliseconds(cur_time - cur_message_issue_time); - StartProcessingTimers(); + helper_.StartProcessingTimers(queueing_time); } virtual void DidProcessMessage(const MSG& msg) { - EndProcessingTimers(); + helper_.EndProcessingTimers(); } #elif defined(TOOLKIT_USES_GTK) virtual void WillProcessEvent(GdkEvent* event) { - begin_process_message_ = TimeTicks::Now(); // TODO(evanm): we want to set queueing_time_ using // gdk_event_get_time, but how do you convert that info // into a delta? // guint event_time = gdk_event_get_time(event); - queueing_time_ = base::TimeDelta::FromMilliseconds(0); - StartProcessingTimers(); + base::TimeDelta queueing_time = base::TimeDelta::FromMilliseconds(0); + helper_.StartProcessingTimers(queueing_time); } virtual void DidProcessEvent(GdkEvent* event) { - EndProcessingTimers(); + helper_.EndProcessingTimers(); } #endif private: - friend class base::RefCountedThreadSafe<JankObserver>; - - ~JankObserver() {} - - const TimeDelta MaxMessageDelay_; - - // Time at which the current message processing began. - TimeTicks begin_process_message_; + friend class base::RefCountedThreadSafe<UIJankObserver>; - // Time the current message spent in the queue -- delta between message - // construction time and message processing time. - TimeDelta queueing_time_; + ~UIJankObserver() {} - // Counters for the two types of jank we measure. - StatsCounter slow_processing_counter_; // Messages with long processing time. - StatsCounter queueing_delay_counter_; // Messages with long queueing delay. - scoped_refptr<Histogram> process_times_; // Time spent processing task. - scoped_refptr<Histogram> total_times_; // Total queueing plus processing. - JankWatchdog total_time_watchdog_; // Watching for excessive total_time. + JankObserverHelper helper_; - DISALLOW_COPY_AND_ASSIGN(JankObserver); + DISALLOW_COPY_AND_ASSIGN(UIJankObserver); }; // These objects are created by InstallJankometer and leaked. -JankObserver* ui_observer = NULL; -JankObserver* io_observer = NULL; +const scoped_refptr<UIJankObserver>* ui_observer = NULL; +const scoped_refptr<IOJankObserver>* io_observer = NULL; } // namespace @@ -239,36 +331,37 @@ void InstallJankometer(const CommandLine& parsed_command_line) { } // Install on the UI thread. - ui_observer = new JankObserver( - "UI", - TimeDelta::FromMilliseconds(kMaxUIMessageDelayMs), - ui_watchdog_enabled); - ui_observer->AddRef(); - ui_observer->AttachToCurrentThread(); + ui_observer = new scoped_refptr<UIJankObserver>( + new UIJankObserver( + "UI", + TimeDelta::FromMilliseconds(kMaxUIMessageDelayMs), + ui_watchdog_enabled)); + (*ui_observer)->AttachToCurrentThread(); // Now install on the I/O thread. Hiccups on that thread will block // interaction with web pages. We must proxy to that thread before we can // add our observer. - io_observer = new JankObserver( - "IO", - TimeDelta::FromMilliseconds(kMaxIOMessageDelayMs), - io_watchdog_enabled); - io_observer->AddRef(); + io_observer = new scoped_refptr<IOJankObserver>( + new IOJankObserver( + "IO", + TimeDelta::FromMilliseconds(kMaxIOMessageDelayMs), + io_watchdog_enabled)); ChromeThread::PostTask( ChromeThread::IO, FROM_HERE, - NewRunnableMethod(io_observer, &JankObserver::AttachToCurrentThread)); + NewRunnableMethod(io_observer->get(), + &IOJankObserver::AttachToCurrentThread)); } void UninstallJankometer() { if (ui_observer) { - ui_observer->DetachFromCurrentThread(); - ui_observer->Release(); + (*ui_observer)->DetachFromCurrentThread(); + delete ui_observer; ui_observer = NULL; } if (io_observer) { // IO thread can't be running when we remove observers. DCHECK((!g_browser_process) || !(g_browser_process->io_thread())); - io_observer->Release(); + delete io_observer; io_observer = NULL; } } |