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 |