Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(841)

Side by Side Diff: chrome/browser/metrics/first_web_contents_profiler.cc

Issue 1422773003: Revert "Record time for UI task to execute under 1/60s" (Closed) Base URL: https://chromium.googlesource.com/chromium/src.git@ab3_firstpaint2
Patch Set: git cl format Created 5 years, 1 month ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch
OLDNEW
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
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)
OLDNEW
« no previous file with comments | « chrome/browser/metrics/first_web_contents_profiler.h ('k') | tools/metrics/histograms/histograms.xml » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698