| OLD | NEW |
| 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. |
| 2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
| 3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
| 4 | 4 |
| 5 #include "chrome/browser/jankometer.h" | 5 #include "chrome/browser/jankometer.h" |
| 6 | 6 |
| 7 #include <limits> | 7 #include <limits> |
| 8 | 8 |
| 9 #include "base/basictypes.h" | 9 #include "base/basictypes.h" |
| 10 #include "base/bind.h" | 10 #include "base/bind.h" |
| (...skipping 30 matching lines...) Expand all Loading... |
| 41 const int kMaxIOMessageDelayMs = 200; | 41 const int kMaxIOMessageDelayMs = 200; |
| 42 #else | 42 #else |
| 43 const int kMaxUIMessageDelayMs = 500; | 43 const int kMaxUIMessageDelayMs = 500; |
| 44 const int kMaxIOMessageDelayMs = 400; | 44 const int kMaxIOMessageDelayMs = 400; |
| 45 #endif | 45 #endif |
| 46 | 46 |
| 47 // Maximum processing time (excluding queueing delay) for a message before | 47 // Maximum processing time (excluding queueing delay) for a message before |
| 48 // considering it delayed. | 48 // considering it delayed. |
| 49 const int kMaxMessageProcessingMs = 100; | 49 const int kMaxMessageProcessingMs = 100; |
| 50 | 50 |
| 51 #if defined(OS_WIN) | |
| 52 // TODO(brettw) Consider making this a pref. | 51 // TODO(brettw) Consider making this a pref. |
| 53 const bool kPlaySounds = false; | 52 const bool kPlaySounds = false; |
| 54 #endif | |
| 55 | 53 |
| 56 //------------------------------------------------------------------------------ | 54 //------------------------------------------------------------------------------ |
| 57 // Provide a special watchdog to make it easy to set the breakpoint on this | 55 // Provide a special watchdog to make it easy to set the breakpoint on this |
| 58 // class only. | 56 // class only. |
| 59 class JankWatchdog : public base::Watchdog { | 57 class JankWatchdog : public base::Watchdog { |
| 60 public: | 58 public: |
| 61 JankWatchdog(const TimeDelta& duration, | 59 JankWatchdog(const TimeDelta& duration, |
| 62 const std::string& thread_watched_name, | 60 const std::string& thread_watched_name, |
| 63 bool enabled) | 61 bool enabled) |
| 64 : Watchdog(duration, thread_watched_name, enabled), | 62 : Watchdog(duration, thread_watched_name, enabled), |
| (...skipping 92 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 157 void JankObserverHelper::StartProcessingTimers(const TimeDelta& queueing_time) { | 155 void JankObserverHelper::StartProcessingTimers(const TimeDelta& queueing_time) { |
| 158 DCHECK(measure_current_message_); | 156 DCHECK(measure_current_message_); |
| 159 begin_process_message_ = TimeTicks::Now(); | 157 begin_process_message_ = TimeTicks::Now(); |
| 160 queueing_time_ = queueing_time; | 158 queueing_time_ = queueing_time; |
| 161 | 159 |
| 162 // Simulate arming when the message entered the queue. | 160 // Simulate arming when the message entered the queue. |
| 163 total_time_watchdog_.ArmSomeTimeDeltaAgo(queueing_time_); | 161 total_time_watchdog_.ArmSomeTimeDeltaAgo(queueing_time_); |
| 164 if (queueing_time_ > max_message_delay_) { | 162 if (queueing_time_ > max_message_delay_) { |
| 165 // Message is too delayed. | 163 // Message is too delayed. |
| 166 queueing_delay_counter_.Increment(); | 164 queueing_delay_counter_.Increment(); |
| 167 #if defined(OS_WIN) | |
| 168 if (kPlaySounds) | 165 if (kPlaySounds) |
| 169 MessageBeep(MB_ICONASTERISK); | 166 MessageBeep(MB_ICONASTERISK); |
| 170 #endif | |
| 171 } | 167 } |
| 172 } | 168 } |
| 173 | 169 |
| 174 // Called when a message has just finished processing, finalizes | 170 // Called when a message has just finished processing, finalizes |
| 175 // per-message variables and timers. | 171 // per-message variables and timers. |
| 176 void JankObserverHelper::EndProcessingTimers() { | 172 void JankObserverHelper::EndProcessingTimers() { |
| 177 if (!measure_current_message_) | 173 if (!measure_current_message_) |
| 178 return; | 174 return; |
| 179 total_time_watchdog_.Disarm(); | 175 total_time_watchdog_.Disarm(); |
| 180 TimeTicks now = TimeTicks::Now(); | 176 TimeTicks now = TimeTicks::Now(); |
| 181 if (begin_process_message_ != TimeTicks()) { | 177 if (begin_process_message_ != TimeTicks()) { |
| 182 TimeDelta processing_time = now - begin_process_message_; | 178 TimeDelta processing_time = now - begin_process_message_; |
| 183 process_times_->AddTime(processing_time); | 179 process_times_->AddTime(processing_time); |
| 184 total_times_->AddTime(queueing_time_ + processing_time); | 180 total_times_->AddTime(queueing_time_ + processing_time); |
| 185 } | 181 } |
| 186 if (now - begin_process_message_ > | 182 if (now - begin_process_message_ > |
| 187 TimeDelta::FromMilliseconds(kMaxMessageProcessingMs)) { | 183 TimeDelta::FromMilliseconds(kMaxMessageProcessingMs)) { |
| 188 // Message took too long to process. | 184 // Message took too long to process. |
| 189 slow_processing_counter_.Increment(); | 185 slow_processing_counter_.Increment(); |
| 190 #if defined(OS_WIN) | |
| 191 if (kPlaySounds) | 186 if (kPlaySounds) |
| 192 MessageBeep(MB_ICONHAND); | 187 MessageBeep(MB_ICONHAND); |
| 193 #endif | |
| 194 } | 188 } |
| 195 | 189 |
| 196 // Reset message specific times. | 190 // Reset message specific times. |
| 197 begin_process_message_ = base::TimeTicks(); | 191 begin_process_message_ = base::TimeTicks(); |
| 198 queueing_time_ = base::TimeDelta(); | 192 queueing_time_ = base::TimeDelta(); |
| 199 } | 193 } |
| 200 | 194 |
| 201 bool JankObserverHelper::MessageWillBeMeasured() { | 195 bool JankObserverHelper::MessageWillBeMeasured() { |
| 202 measure_current_message_ = events_till_measurement_ <= 0; | 196 measure_current_message_ = events_till_measurement_ <= 0; |
| 203 if (!measure_current_message_) | 197 if (!measure_current_message_) |
| (...skipping 93 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 297 return; | 291 return; |
| 298 base::TimeTicks now = base::TimeTicks::Now(); | 292 base::TimeTicks now = base::TimeTicks::Now(); |
| 299 const base::TimeDelta queueing_time = now - pending_task.time_posted; | 293 const base::TimeDelta queueing_time = now - pending_task.time_posted; |
| 300 helper_.StartProcessingTimers(queueing_time); | 294 helper_.StartProcessingTimers(queueing_time); |
| 301 } | 295 } |
| 302 | 296 |
| 303 virtual void DidProcessTask(const base::PendingTask& pending_task) OVERRIDE { | 297 virtual void DidProcessTask(const base::PendingTask& pending_task) OVERRIDE { |
| 304 helper_.EndProcessingTimers(); | 298 helper_.EndProcessingTimers(); |
| 305 } | 299 } |
| 306 | 300 |
| 307 #if defined(OS_WIN) | |
| 308 virtual base::EventStatus WillProcessEvent( | 301 virtual base::EventStatus WillProcessEvent( |
| 309 const base::NativeEvent& event) OVERRIDE { | 302 const base::NativeEvent& event) OVERRIDE { |
| 310 if (!helper_.MessageWillBeMeasured()) | 303 if (!helper_.MessageWillBeMeasured()) |
| 311 return base::EVENT_CONTINUE; | 304 return base::EVENT_CONTINUE; |
| 312 // GetMessageTime returns a LONG (signed 32-bit) and GetTickCount returns | 305 // GetMessageTime returns a LONG (signed 32-bit) and GetTickCount returns |
| 313 // a DWORD (unsigned 32-bit). They both wrap around when the time is longer | 306 // a DWORD (unsigned 32-bit). They both wrap around when the time is longer |
| 314 // than they can hold. I'm not sure if GetMessageTime wraps around to 0, | 307 // than they can hold. I'm not sure if GetMessageTime wraps around to 0, |
| 315 // or if the original time comes from GetTickCount, it might wrap around | 308 // or if the original time comes from GetTickCount, it might wrap around |
| 316 // to -1. | 309 // to -1. |
| 317 // | 310 // |
| 318 // Therefore, I cast to DWORD so if it wraps to -1 we will correct it. If | 311 // Therefore, I cast to DWORD so if it wraps to -1 we will correct it. If |
| 319 // it doesn't, then our time delta will be negative if a message happens | 312 // it doesn't, then our time delta will be negative if a message happens |
| 320 // to straddle the wraparound point, it will still be OK. | 313 // to straddle the wraparound point, it will still be OK. |
| 321 DWORD cur_message_issue_time = static_cast<DWORD>(event.time); | 314 DWORD cur_message_issue_time = static_cast<DWORD>(event.time); |
| 322 DWORD cur_time = GetTickCount(); | 315 DWORD cur_time = GetTickCount(); |
| 323 base::TimeDelta queueing_time = | 316 base::TimeDelta queueing_time = |
| 324 base::TimeDelta::FromMilliseconds(cur_time - cur_message_issue_time); | 317 base::TimeDelta::FromMilliseconds(cur_time - cur_message_issue_time); |
| 325 | 318 |
| 326 helper_.StartProcessingTimers(queueing_time); | 319 helper_.StartProcessingTimers(queueing_time); |
| 327 return base::EVENT_CONTINUE; | 320 return base::EVENT_CONTINUE; |
| 328 } | 321 } |
| 329 | 322 |
| 330 virtual void DidProcessEvent(const base::NativeEvent& event) OVERRIDE { | 323 virtual void DidProcessEvent(const base::NativeEvent& event) OVERRIDE { |
| 331 helper_.EndProcessingTimers(); | 324 helper_.EndProcessingTimers(); |
| 332 } | 325 } |
| 333 #elif defined(USE_AURA) | |
| 334 virtual base::EventStatus WillProcessEvent( | |
| 335 const base::NativeEvent& event) OVERRIDE { | |
| 336 return base::EVENT_CONTINUE; | |
| 337 } | |
| 338 | |
| 339 virtual void DidProcessEvent(const base::NativeEvent& event) OVERRIDE { | |
| 340 } | |
| 341 #elif defined(TOOLKIT_GTK) | |
| 342 virtual void WillProcessEvent(GdkEvent* event) OVERRIDE { | |
| 343 if (!helper_.MessageWillBeMeasured()) | |
| 344 return; | |
| 345 // TODO(evanm): we want to set queueing_time_ using | |
| 346 // gdk_event_get_time, but how do you convert that info | |
| 347 // into a delta? | |
| 348 // guint event_time = gdk_event_get_time(event); | |
| 349 base::TimeDelta queueing_time = base::TimeDelta::FromMilliseconds(0); | |
| 350 helper_.StartProcessingTimers(queueing_time); | |
| 351 } | |
| 352 | |
| 353 virtual void DidProcessEvent(GdkEvent* event) OVERRIDE { | |
| 354 helper_.EndProcessingTimers(); | |
| 355 } | |
| 356 #endif | |
| 357 | 326 |
| 358 private: | 327 private: |
| 359 friend class base::RefCountedThreadSafe<UIJankObserver>; | 328 friend class base::RefCountedThreadSafe<UIJankObserver>; |
| 360 | 329 |
| 361 virtual ~UIJankObserver() {} | 330 virtual ~UIJankObserver() {} |
| 362 | 331 |
| 363 JankObserverHelper helper_; | 332 JankObserverHelper helper_; |
| 364 | 333 |
| 365 DISALLOW_COPY_AND_ASSIGN(UIJankObserver); | 334 DISALLOW_COPY_AND_ASSIGN(UIJankObserver); |
| 366 }; | 335 }; |
| (...skipping 51 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 418 delete ui_observer; | 387 delete ui_observer; |
| 419 ui_observer = NULL; | 388 ui_observer = NULL; |
| 420 } | 389 } |
| 421 if (io_observer) { | 390 if (io_observer) { |
| 422 // IO thread can't be running when we remove observers. | 391 // IO thread can't be running when we remove observers. |
| 423 DCHECK((!g_browser_process) || !(g_browser_process->io_thread())); | 392 DCHECK((!g_browser_process) || !(g_browser_process->io_thread())); |
| 424 delete io_observer; | 393 delete io_observer; |
| 425 io_observer = NULL; | 394 io_observer = NULL; |
| 426 } | 395 } |
| 427 } | 396 } |
| OLD | NEW |