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 |