| OLD | NEW |
| 1 // Copyright 2014 The Chromium Authors. All rights reserved. | 1 // Copyright 2014 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 #if !defined(OS_ANDROID) | 5 #if !defined(OS_ANDROID) |
| 6 | 6 |
| 7 #include "chrome/browser/metrics/first_web_contents_profiler.h" | 7 #include "chrome/browser/metrics/first_web_contents_profiler.h" |
| 8 | 8 |
| 9 #include <string> | 9 #include <string> |
| 10 | 10 |
| 11 #include "base/location.h" | 11 #include "base/location.h" |
| 12 #include "base/logging.h" | 12 #include "base/logging.h" |
| 13 #include "base/metrics/histogram_macros.h" | 13 #include "base/metrics/histogram_macros.h" |
| 14 #include "base/process/process_info.h" | |
| 15 #include "base/single_thread_task_runner.h" | |
| 16 #include "base/thread_task_runner_handle.h" | |
| 17 #include "base/time/time.h" | 14 #include "base/time/time.h" |
| 18 #include "chrome/browser/ui/browser.h" | 15 #include "chrome/browser/ui/browser.h" |
| 19 #include "chrome/browser/ui/browser_iterator.h" | 16 #include "chrome/browser/ui/browser_iterator.h" |
| 20 #include "chrome/browser/ui/tabs/tab_strip_model.h" | 17 #include "chrome/browser/ui/tabs/tab_strip_model.h" |
| 21 #include "components/metrics/profiler/tracking_synchronizer.h" | 18 #include "components/metrics/profiler/tracking_synchronizer.h" |
| 22 #include "components/metrics/proto/profiler_event.pb.h" | 19 #include "components/metrics/proto/profiler_event.pb.h" |
| 23 #include "components/startup_metric_utils/startup_metric_utils.h" | 20 #include "components/startup_metric_utils/startup_metric_utils.h" |
| 24 #include "content/public/browser/browser_thread.h" | |
| 25 #include "content/public/browser/navigation_handle.h" | 21 #include "content/public/browser/navigation_handle.h" |
| 26 | 22 |
| 27 namespace { | |
| 28 | |
| 29 // The initial delay for responsiveness prober in milliseconds. | |
| 30 const int kInitialDelayMs = 20; | |
| 31 | |
| 32 // The following is the multiplier is used to delay the probe for | |
| 33 // responsiveness. | |
| 34 const double kBackoffMultiplier = 1.5; | |
| 35 | |
| 36 // The maximum backoff delay in milliseconds. | |
| 37 const int kMaxDelayMs = 250; | |
| 38 | |
| 39 void DelayedRecordUIResponsiveness( | |
| 40 base::HistogramBase* responsiveness_histogram, | |
| 41 base::HistogramBase* unresponsiveness_histogram, | |
| 42 base::Time start_recording_time, | |
| 43 base::TimeDelta next_task_delay); | |
| 44 | |
| 45 // Records the elapsed time for a task to execute a UI task under 1/60s after | |
| 46 // the first WebContent was painted at least once. If after few tries it is | |
| 47 // unable to execute under 1/60s it records the execution time of a task. | |
| 48 void RecordUIResponsiveness(base::HistogramBase* responsiveness_histogram, | |
| 49 base::HistogramBase* unresponsiveness_histogram, | |
| 50 base::Time start_recording_time, | |
| 51 base::Time task_posted_time, | |
| 52 base::TimeDelta next_task_delay) { | |
| 53 DCHECK(!start_recording_time.is_null()); | |
| 54 DCHECK(!task_posted_time.is_null()); | |
| 55 base::Time now = base::Time::Now(); | |
| 56 base::TimeDelta elapsed = now - task_posted_time; | |
| 57 | |
| 58 // Task executed in less then 1/60s. | |
| 59 if (elapsed.InMilliseconds() <= (1000 / 60)) { | |
| 60 responsiveness_histogram->AddTime(now - start_recording_time); | |
| 61 } else if (next_task_delay.InMilliseconds() > kMaxDelayMs) { | |
| 62 // Records elapsed time to execute last task. | |
| 63 unresponsiveness_histogram->AddTime(elapsed); | |
| 64 } else { | |
| 65 base::ThreadTaskRunnerHandle::Get()->PostDelayedTask( | |
| 66 FROM_HERE, | |
| 67 base::Bind(&DelayedRecordUIResponsiveness, responsiveness_histogram, | |
| 68 unresponsiveness_histogram, start_recording_time, | |
| 69 next_task_delay * kBackoffMultiplier), | |
| 70 next_task_delay); | |
| 71 } | |
| 72 } | |
| 73 | |
| 74 // Used for posting |RecordUIResponsiveness| without delay, so that | |
| 75 // |RecordUIResponsiveness| can do more accurate time calculation for elapsed | |
| 76 // time of the task to complete. | |
| 77 void DelayedRecordUIResponsiveness( | |
| 78 base::HistogramBase* responsiveness_histogram, | |
| 79 base::HistogramBase* unresponsiveness_histogram, | |
| 80 base::Time start_recording_time, | |
| 81 base::TimeDelta next_task_delay) { | |
| 82 base::ThreadTaskRunnerHandle::Get()->PostTask( | |
| 83 FROM_HERE, base::Bind(&RecordUIResponsiveness, responsiveness_histogram, | |
| 84 unresponsiveness_histogram, start_recording_time, | |
| 85 base::Time::Now(), next_task_delay)); | |
| 86 } | |
| 87 | |
| 88 // Sends the first task for measuring UI Responsiveness. | |
| 89 void MeasureUIResponsiveness(base::HistogramBase* responsiveness_histogram, | |
| 90 base::HistogramBase* unresponsiveness_histogram) { | |
| 91 base::ThreadTaskRunnerHandle::Get()->PostTask( | |
| 92 FROM_HERE, | |
| 93 base::Bind(&RecordUIResponsiveness, responsiveness_histogram, | |
| 94 unresponsiveness_histogram, base::Time::Now(), | |
| 95 base::Time::Now(), | |
| 96 base::TimeDelta::FromMilliseconds(kInitialDelayMs))); | |
| 97 } | |
| 98 | |
| 99 } // namespace | |
| 100 | |
| 101 scoped_ptr<FirstWebContentsProfiler> | 23 scoped_ptr<FirstWebContentsProfiler> |
| 102 FirstWebContentsProfiler::CreateProfilerForFirstWebContents( | 24 FirstWebContentsProfiler::CreateProfilerForFirstWebContents( |
| 103 Delegate* delegate) { | 25 Delegate* delegate) { |
| 104 DCHECK(delegate); | 26 DCHECK(delegate); |
| 105 for (chrome::BrowserIterator iterator; !iterator.done(); iterator.Next()) { | 27 for (chrome::BrowserIterator iterator; !iterator.done(); iterator.Next()) { |
| 106 Browser* browser = *iterator; | 28 Browser* browser = *iterator; |
| 107 content::WebContents* web_contents = | 29 content::WebContents* web_contents = |
| 108 browser->tab_strip_model()->GetActiveWebContents(); | 30 browser->tab_strip_model()->GetActiveWebContents(); |
| 109 if (web_contents) { | 31 if (web_contents) { |
| 110 return scoped_ptr<FirstWebContentsProfiler>( | 32 return scoped_ptr<FirstWebContentsProfiler>( |
| 111 new FirstWebContentsProfiler(web_contents, delegate)); | 33 new FirstWebContentsProfiler(web_contents, delegate)); |
| 112 } | 34 } |
| 113 } | 35 } |
| 114 return nullptr; | 36 return nullptr; |
| 115 } | 37 } |
| 116 | 38 |
| 117 FirstWebContentsProfiler::FirstWebContentsProfiler( | 39 FirstWebContentsProfiler::FirstWebContentsProfiler( |
| 118 content::WebContents* web_contents, | 40 content::WebContents* web_contents, |
| 119 Delegate* delegate) | 41 Delegate* delegate) |
| 120 : content::WebContentsObserver(web_contents), | 42 : content::WebContentsObserver(web_contents), |
| 121 collected_paint_metric_(false), | 43 collected_paint_metric_(false), |
| 122 collected_load_metric_(false), | 44 collected_load_metric_(false), |
| 123 collected_main_navigation_start_metric_(false), | 45 collected_main_navigation_start_metric_(false), |
| 124 collected_main_navigation_finished_metric_(false), | 46 collected_main_navigation_finished_metric_(false), |
| 125 finished_(false), | 47 finished_(false), |
| 126 delegate_(delegate), | 48 delegate_(delegate) {} |
| 127 responsiveness_histogram_(NULL), | |
| 128 responsiveness_1sec_histogram_(NULL), | |
| 129 responsiveness_10sec_histogram_(NULL), | |
| 130 unresponsiveness_histogram_(NULL), | |
| 131 unresponsiveness_1sec_histogram_(NULL), | |
| 132 unresponsiveness_10sec_histogram_(NULL) { | |
| 133 InitHistograms(); | |
| 134 } | |
| 135 | 49 |
| 136 void FirstWebContentsProfiler::DidFirstVisuallyNonEmptyPaint() { | 50 void FirstWebContentsProfiler::DidFirstVisuallyNonEmptyPaint() { |
| 137 if (collected_paint_metric_) | 51 if (collected_paint_metric_) |
| 138 return; | 52 return; |
| 139 if (startup_metric_utils::WasNonBrowserUIDisplayed()) { | 53 if (startup_metric_utils::WasNonBrowserUIDisplayed()) { |
| 140 FinishedCollectingMetrics(FinishReason::ABANDON_BLOCKING_UI); | 54 FinishedCollectingMetrics(FinishReason::ABANDON_BLOCKING_UI); |
| 141 return; | 55 return; |
| 142 } | 56 } |
| 143 | 57 |
| 144 collected_paint_metric_ = true; | 58 collected_paint_metric_ = true; |
| 145 const base::Time now = base::Time::Now(); | 59 const base::Time now = base::Time::Now(); |
| 146 // Record the old metric unconditionally. | 60 // Record the old metric unconditionally. |
| 147 startup_metric_utils::RecordDeprecatedFirstWebContentsNonEmptyPaint(now); | 61 startup_metric_utils::RecordDeprecatedFirstWebContentsNonEmptyPaint(now); |
| 148 if (!finished_) | 62 if (!finished_) |
| 149 startup_metric_utils::RecordFirstWebContentsNonEmptyPaint(now); | 63 startup_metric_utils::RecordFirstWebContentsNonEmptyPaint(now); |
| 150 | 64 |
| 151 metrics::TrackingSynchronizer::OnProfilingPhaseCompleted( | 65 metrics::TrackingSynchronizer::OnProfilingPhaseCompleted( |
| 152 metrics::ProfilerEventProto::EVENT_FIRST_NONEMPTY_PAINT); | 66 metrics::ProfilerEventProto::EVENT_FIRST_NONEMPTY_PAINT); |
| 153 | 67 |
| 154 // Measures responsiveness now. | |
| 155 MeasureUIResponsiveness(responsiveness_histogram_, | |
| 156 unresponsiveness_histogram_); | |
| 157 | |
| 158 // As it was observed that sometimes the task queue can be free immediately | |
| 159 // after the first paint but get overloaded shortly thereafter, here we | |
| 160 // measures responsiveness after 1 second and 10 seconds to observe the | |
| 161 // possible effect of those late tasks. | |
| 162 base::ThreadTaskRunnerHandle::Get()->PostDelayedTask( | |
| 163 FROM_HERE, | |
| 164 base::Bind(&MeasureUIResponsiveness, responsiveness_1sec_histogram_, | |
| 165 unresponsiveness_1sec_histogram_), | |
| 166 base::TimeDelta::FromSeconds(1)); | |
| 167 | |
| 168 base::ThreadTaskRunnerHandle::Get()->PostDelayedTask( | |
| 169 FROM_HERE, | |
| 170 base::Bind(&MeasureUIResponsiveness, responsiveness_10sec_histogram_, | |
| 171 unresponsiveness_10sec_histogram_), | |
| 172 base::TimeDelta::FromSeconds(10)); | |
| 173 | |
| 174 if (IsFinishedCollectingMetrics()) | 68 if (IsFinishedCollectingMetrics()) |
| 175 FinishedCollectingMetrics(FinishReason::DONE); | 69 FinishedCollectingMetrics(FinishReason::DONE); |
| 176 } | 70 } |
| 177 | 71 |
| 178 void FirstWebContentsProfiler::DocumentOnLoadCompletedInMainFrame() { | 72 void FirstWebContentsProfiler::DocumentOnLoadCompletedInMainFrame() { |
| 179 if (collected_load_metric_) | 73 if (collected_load_metric_) |
| 180 return; | 74 return; |
| 181 if (startup_metric_utils::WasNonBrowserUIDisplayed()) { | 75 if (startup_metric_utils::WasNonBrowserUIDisplayed()) { |
| 182 FinishedCollectingMetrics(FinishReason::ABANDON_BLOCKING_UI); | 76 FinishedCollectingMetrics(FinishReason::ABANDON_BLOCKING_UI); |
| 183 return; | 77 return; |
| (...skipping 90 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 274 UMA_HISTOGRAM_ENUMERATION("Startup.FirstWebContents.FinishReason_NoLoad", | 168 UMA_HISTOGRAM_ENUMERATION("Startup.FirstWebContents.FinishReason_NoLoad", |
| 275 finish_reason, FinishReason::ENUM_MAX); | 169 finish_reason, FinishReason::ENUM_MAX); |
| 276 } | 170 } |
| 277 finished_ = true; | 171 finished_ = true; |
| 278 } | 172 } |
| 279 // TODO(gab): Delete right away when getting rid of |finished_|. | 173 // TODO(gab): Delete right away when getting rid of |finished_|. |
| 280 if (IsFinishedCollectingMetrics()) | 174 if (IsFinishedCollectingMetrics()) |
| 281 delegate_->ProfilerFinishedCollectingMetrics(); | 175 delegate_->ProfilerFinishedCollectingMetrics(); |
| 282 } | 176 } |
| 283 | 177 |
| 284 void FirstWebContentsProfiler::InitHistograms() { | |
| 285 const std::string responsiveness_histogram_name = | |
| 286 "Startup.FirstWebContents.UIResponsive"; | |
| 287 responsiveness_histogram_ = base::Histogram::FactoryTimeGet( | |
| 288 responsiveness_histogram_name, base::TimeDelta::FromMilliseconds(1), | |
| 289 base::TimeDelta::FromSeconds(60), 100, | |
| 290 base::Histogram::kUmaTargetedHistogramFlag); | |
| 291 | |
| 292 const std::string responsiveness_1sec_histogram_name = | |
| 293 "Startup.FirstWebContents.UIResponsive_1sec"; | |
| 294 responsiveness_1sec_histogram_ = base::Histogram::FactoryTimeGet( | |
| 295 responsiveness_1sec_histogram_name, base::TimeDelta::FromMilliseconds(1), | |
| 296 base::TimeDelta::FromSeconds(60), 100, | |
| 297 base::Histogram::kUmaTargetedHistogramFlag); | |
| 298 | |
| 299 const std::string responsiveness_10sec_histogram_name = | |
| 300 "Startup.FirstWebContents.UIResponsive_10sec"; | |
| 301 responsiveness_10sec_histogram_ = base::Histogram::FactoryTimeGet( | |
| 302 responsiveness_10sec_histogram_name, base::TimeDelta::FromMilliseconds(1), | |
| 303 base::TimeDelta::FromSeconds(60), 100, | |
| 304 base::Histogram::kUmaTargetedHistogramFlag); | |
| 305 | |
| 306 const std::string unresponsiveness_histogram_name = | |
| 307 "Startup.FirstWebContents.UINotResponsive"; | |
| 308 unresponsiveness_histogram_ = base::Histogram::FactoryTimeGet( | |
| 309 unresponsiveness_histogram_name, base::TimeDelta::FromMilliseconds(1), | |
| 310 base::TimeDelta::FromSeconds(60), 100, | |
| 311 base::Histogram::kUmaTargetedHistogramFlag); | |
| 312 | |
| 313 const std::string unresponsiveness_1sec_histogram_name = | |
| 314 "Startup.FirstWebContents.UINotResponsive_1sec"; | |
| 315 unresponsiveness_1sec_histogram_ = base::Histogram::FactoryTimeGet( | |
| 316 unresponsiveness_1sec_histogram_name, | |
| 317 base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromSeconds(60), | |
| 318 100, base::Histogram::kUmaTargetedHistogramFlag); | |
| 319 | |
| 320 const std::string unresponsiveness_10sec_histogram_name = | |
| 321 "Startup.FirstWebContents.UINotResponsive_10sec"; | |
| 322 unresponsiveness_10sec_histogram_ = base::Histogram::FactoryTimeGet( | |
| 323 unresponsiveness_10sec_histogram_name, | |
| 324 base::TimeDelta::FromMilliseconds(1), base::TimeDelta::FromSeconds(60), | |
| 325 100, base::Histogram::kUmaTargetedHistogramFlag); | |
| 326 } | |
| 327 #endif // !defined(OS_ANDROID) | 178 #endif // !defined(OS_ANDROID) |
| OLD | NEW |