| 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 #include "content/browser/renderer_host/input/render_widget_host_latency_tracker
.h" | 5 #include "content/browser/renderer_host/input/render_widget_host_latency_tracker
.h" |
| 6 | 6 |
| 7 #include "base/logging.h" | 7 #include "base/logging.h" |
| 8 #include "base/metrics/histogram.h" | 8 #include "base/metrics/histogram.h" |
| 9 #include "content/browser/renderer_host/render_widget_host_impl.h" | 9 #include "content/browser/renderer_host/render_widget_host_impl.h" |
| 10 | 10 |
| (...skipping 117 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 128 "Event.Latency.Browser.TouchAcked", | 128 "Event.Latency.Browser.TouchAcked", |
| 129 acked_delta.InMicroseconds(), 1, 1000000, 100); | 129 acked_delta.InMicroseconds(), 1, 1000000, 100); |
| 130 break; | 130 break; |
| 131 default: | 131 default: |
| 132 NOTREACHED(); | 132 NOTREACHED(); |
| 133 break; | 133 break; |
| 134 } | 134 } |
| 135 } | 135 } |
| 136 } | 136 } |
| 137 | 137 |
| 138 // Touch to scroll latency that is mostly under 1 second. |
| 139 #define UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY(name, start, end) \ |
| 140 UMA_HISTOGRAM_CUSTOM_COUNTS( \ |
| 141 name, (end.event_time - start.event_time).InMicroseconds(), 1, 1000000, \ |
| 142 100) |
| 143 |
| 138 // Long scroll latency component that is mostly under 200ms. | 144 // Long scroll latency component that is mostly under 200ms. |
| 139 #define UMA_HISTOGRAM_SCROLL_LATENCY_LONG(name, start, end) \ | 145 #define UMA_HISTOGRAM_SCROLL_LATENCY_LONG(name, start, end) \ |
| 140 UMA_HISTOGRAM_CUSTOM_COUNTS( \ | 146 UMA_HISTOGRAM_CUSTOM_COUNTS( \ |
| 141 name, \ | 147 name, \ |
| 142 (end.event_time - start.event_time).InMicroseconds(), \ | 148 (end.event_time - start.event_time).InMicroseconds(), \ |
| 143 1000, 200000, 50) | 149 1000, 200000, 50) |
| 144 | 150 |
| 145 // Short scroll latency component that is mostly under 50ms. | 151 // Short scroll latency component that is mostly under 50ms. |
| 146 #define UMA_HISTOGRAM_SCROLL_LATENCY_SHORT(name, start, end) \ | 152 #define UMA_HISTOGRAM_SCROLL_LATENCY_SHORT(name, start, end) \ |
| 147 UMA_HISTOGRAM_CUSTOM_COUNTS( \ | 153 UMA_HISTOGRAM_CUSTOM_COUNTS( \ |
| 148 name, \ | 154 name, \ |
| 149 (end.event_time - start.event_time).InMicroseconds(), \ | 155 (end.event_time - start.event_time).InMicroseconds(), \ |
| 150 1, 50000, 50) | 156 1, 50000, 50) |
| 151 | 157 |
| 152 void ComputeScrollLatencyHistograms( | 158 void ComputeScrollLatencyHistograms( |
| 153 const LatencyInfo::LatencyComponent& gpu_swap_component, | 159 const LatencyInfo::LatencyComponent& gpu_swap_begin_component, |
| 160 const LatencyInfo::LatencyComponent& gpu_swap_end_component, |
| 154 int64 latency_component_id, | 161 int64 latency_component_id, |
| 155 const LatencyInfo& latency) { | 162 const LatencyInfo& latency) { |
| 156 DCHECK(!gpu_swap_component.event_time.is_null()); | 163 DCHECK(!gpu_swap_begin_component.event_time.is_null()); |
| 164 DCHECK(!gpu_swap_end_component.event_time.is_null()); |
| 157 LatencyInfo::LatencyComponent first_original_component, original_component; | 165 LatencyInfo::LatencyComponent first_original_component, original_component; |
| 158 if (latency.FindLatency( | 166 if (latency.FindLatency( |
| 159 ui::INPUT_EVENT_LATENCY_FIRST_SCROLL_UPDATE_ORIGINAL_COMPONENT, | 167 ui::INPUT_EVENT_LATENCY_FIRST_SCROLL_UPDATE_ORIGINAL_COMPONENT, |
| 160 latency_component_id, &first_original_component)) { | 168 latency_component_id, &first_original_component)) { |
| 161 // This UMA metric tracks the time between the final frame swap for the | 169 // This UMA metric tracks the time between the final frame swap for the |
| 162 // first scroll event in a sequence and the original timestamp of that | 170 // first scroll event in a sequence and the original timestamp of that |
| 163 // scroll event's underlying touch event. | 171 // scroll event's underlying touch event. |
| 164 for (size_t i = 0; i < first_original_component.event_count; i++) { | 172 for (size_t i = 0; i < first_original_component.event_count; i++) { |
| 165 UMA_HISTOGRAM_CUSTOM_COUNTS( | 173 UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY( |
| 174 "Event.Latency.TouchToFirstScrollUpdateSwapBegin", |
| 175 first_original_component, gpu_swap_begin_component); |
| 176 // TODO(brianderson): Remove this version once we have enough overlapping |
| 177 // data with the metric above. crbug.com/478845 |
| 178 UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY( |
| 166 "Event.Latency.TouchToFirstScrollUpdateSwap", | 179 "Event.Latency.TouchToFirstScrollUpdateSwap", |
| 167 (gpu_swap_component.event_time - first_original_component.event_time) | 180 first_original_component, gpu_swap_end_component); |
| 168 .InMicroseconds(), | |
| 169 1, 1000000, 100); | |
| 170 } | 181 } |
| 171 original_component = first_original_component; | 182 original_component = first_original_component; |
| 172 } else if (!latency.FindLatency( | 183 } else if (!latency.FindLatency( |
| 173 ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT, | 184 ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT, |
| 174 latency_component_id, &original_component)) { | 185 latency_component_id, &original_component)) { |
| 175 return; | 186 return; |
| 176 } | 187 } |
| 177 | 188 |
| 178 // This UMA metric tracks the time from when the original touch event is | 189 // This UMA metric tracks the time from when the original touch event is |
| 179 // created (averaged if there are multiple) to when the scroll gesture | 190 // created (averaged if there are multiple) to when the scroll gesture |
| 180 // results in final frame swap. | 191 // results in final frame swap. |
| 181 for (size_t i = 0; i < original_component.event_count; i++) { | 192 for (size_t i = 0; i < original_component.event_count; i++) { |
| 182 UMA_HISTOGRAM_CUSTOM_COUNTS( | 193 UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY( |
| 183 "Event.Latency.TouchToScrollUpdateSwap", | 194 "Event.Latency.TouchToScrollUpdateSwapBegin", original_component, |
| 184 (gpu_swap_component.event_time - original_component.event_time) | 195 gpu_swap_begin_component); |
| 185 .InMicroseconds(), | 196 // TODO(brianderson): Remove this version once we have enough overlapping |
| 186 1, 1000000, 100); | 197 // data with the metric above. crbug.com/478845 |
| 198 UMA_HISTOGRAM_TOUCH_TO_SCROLL_LATENCY( |
| 199 "Event.Latency.TouchToScrollUpdateSwap", original_component, |
| 200 gpu_swap_end_component); |
| 187 } | 201 } |
| 188 | 202 |
| 189 // TODO(miletus): Add validation for making sure the following components | 203 // TODO(miletus): Add validation for making sure the following components |
| 190 // are present and their event times are legit. | 204 // are present and their event times are legit. |
| 191 LatencyInfo::LatencyComponent rendering_scheduled_component; | 205 LatencyInfo::LatencyComponent rendering_scheduled_component; |
| 192 bool rendering_scheduled_on_main = latency.FindLatency( | 206 bool rendering_scheduled_on_main = latency.FindLatency( |
| 193 ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_MAIN_COMPONENT, | 207 ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_MAIN_COMPONENT, |
| 194 0, &rendering_scheduled_component); | 208 0, &rendering_scheduled_component); |
| 195 | 209 |
| 196 if (!rendering_scheduled_on_main) { | 210 if (!rendering_scheduled_on_main) { |
| (...skipping 33 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 230 ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, | 244 ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, |
| 231 0, &browser_received_swap_component)) | 245 0, &browser_received_swap_component)) |
| 232 return; | 246 return; |
| 233 | 247 |
| 234 UMA_HISTOGRAM_SCROLL_LATENCY_SHORT( | 248 UMA_HISTOGRAM_SCROLL_LATENCY_SHORT( |
| 235 "Event.Latency.ScrollUpdate.RendererSwapToBrowserNotified", | 249 "Event.Latency.ScrollUpdate.RendererSwapToBrowserNotified", |
| 236 renderer_swap_component, browser_received_swap_component); | 250 renderer_swap_component, browser_received_swap_component); |
| 237 | 251 |
| 238 UMA_HISTOGRAM_SCROLL_LATENCY_LONG( | 252 UMA_HISTOGRAM_SCROLL_LATENCY_LONG( |
| 239 "Event.Latency.ScrollUpdate.BrowserNotifiedToBeforeGpuSwap", | 253 "Event.Latency.ScrollUpdate.BrowserNotifiedToBeforeGpuSwap", |
| 240 browser_received_swap_component, gpu_swap_component); | 254 browser_received_swap_component, gpu_swap_begin_component); |
| 241 | |
| 242 LatencyInfo::LatencyComponent gpu_swap_ack_component; | |
| 243 if (!latency.FindLatency( | |
| 244 ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT, 0, | |
| 245 &gpu_swap_ack_component)) | |
| 246 return; | |
| 247 | 255 |
| 248 UMA_HISTOGRAM_SCROLL_LATENCY_SHORT("Event.Latency.ScrollUpdate.GpuSwap", | 256 UMA_HISTOGRAM_SCROLL_LATENCY_SHORT("Event.Latency.ScrollUpdate.GpuSwap", |
| 249 gpu_swap_component, | 257 gpu_swap_begin_component, |
| 250 gpu_swap_ack_component); | 258 gpu_swap_end_component); |
| 251 } | 259 } |
| 252 | 260 |
| 253 // LatencyComponents generated in the renderer must have component IDs | 261 // LatencyComponents generated in the renderer must have component IDs |
| 254 // provided to them by the browser process. This function adds the correct | 262 // provided to them by the browser process. This function adds the correct |
| 255 // component ID where necessary. | 263 // component ID where necessary. |
| 256 void AddLatencyInfoComponentIds(LatencyInfo* latency, | 264 void AddLatencyInfoComponentIds(LatencyInfo* latency, |
| 257 int64 latency_component_id) { | 265 int64 latency_component_id) { |
| 258 LatencyInfo::LatencyMap new_components; | 266 LatencyInfo::LatencyMap new_components; |
| 259 auto lc = latency->latency_components.begin(); | 267 auto lc = latency->latency_components.begin(); |
| 260 while (lc != latency->latency_components.end()) { | 268 while (lc != latency->latency_components.end()) { |
| (...skipping 137 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 398 DCHECK(latencies); | 406 DCHECK(latencies); |
| 399 for (LatencyInfo& latency : *latencies) { | 407 for (LatencyInfo& latency : *latencies) { |
| 400 AddLatencyInfoComponentIds(&latency, latency_component_id_); | 408 AddLatencyInfoComponentIds(&latency, latency_component_id_); |
| 401 latency.AddLatencyNumber( | 409 latency.AddLatencyNumber( |
| 402 ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, 0, 0); | 410 ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, 0, 0); |
| 403 } | 411 } |
| 404 } | 412 } |
| 405 | 413 |
| 406 void RenderWidgetHostLatencyTracker::OnFrameSwapped( | 414 void RenderWidgetHostLatencyTracker::OnFrameSwapped( |
| 407 const LatencyInfo& latency) { | 415 const LatencyInfo& latency) { |
| 408 LatencyInfo::LatencyComponent gpu_swap_component; | 416 LatencyInfo::LatencyComponent gpu_swap_end_component; |
| 409 if (!latency.FindLatency(ui::INPUT_EVENT_GPU_SWAP_BUFFER_COMPONENT, 0, | 417 if (!latency.FindLatency( |
| 410 &gpu_swap_component)) { | 418 ui::INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT, 0, |
| 419 &gpu_swap_end_component)) { |
| 411 return; | 420 return; |
| 412 } | 421 } |
| 413 | 422 |
| 423 LatencyInfo::LatencyComponent gpu_swap_begin_component; |
| 424 if (!latency.FindLatency(ui::INPUT_EVENT_GPU_SWAP_BUFFER_COMPONENT, 0, |
| 425 &gpu_swap_begin_component)) { |
| 426 return; |
| 427 } |
| 428 |
| 414 LatencyInfo::LatencyComponent tab_switch_component; | 429 LatencyInfo::LatencyComponent tab_switch_component; |
| 415 if (latency.FindLatency(ui::TAB_SHOW_COMPONENT, latency_component_id_, | 430 if (latency.FindLatency(ui::TAB_SHOW_COMPONENT, latency_component_id_, |
| 416 &tab_switch_component)) { | 431 &tab_switch_component)) { |
| 417 base::TimeDelta delta = | 432 base::TimeDelta delta = |
| 418 gpu_swap_component.event_time - tab_switch_component.event_time; | 433 gpu_swap_end_component.event_time - tab_switch_component.event_time; |
| 419 for (size_t i = 0; i < tab_switch_component.event_count; i++) { | 434 for (size_t i = 0; i < tab_switch_component.event_count; i++) { |
| 420 UMA_HISTOGRAM_TIMES("MPArch.RWH_TabSwitchPaintDuration", delta); | 435 UMA_HISTOGRAM_TIMES("MPArch.RWH_TabSwitchPaintDuration", delta); |
| 421 } | 436 } |
| 422 } | 437 } |
| 423 | 438 |
| 424 if (!latency.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT, | 439 if (!latency.FindLatency(ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT, |
| 425 latency_component_id_, nullptr)) { | 440 latency_component_id_, nullptr)) { |
| 426 return; | 441 return; |
| 427 } | 442 } |
| 428 | 443 |
| 429 ComputeScrollLatencyHistograms(gpu_swap_component, latency_component_id_, | 444 ComputeScrollLatencyHistograms(gpu_swap_begin_component, |
| 445 gpu_swap_end_component, latency_component_id_, |
| 430 latency); | 446 latency); |
| 431 | 447 |
| 432 LatencyInfo::LatencyComponent browser_swap_component; | 448 LatencyInfo::LatencyComponent browser_swap_component; |
| 433 if (latency.FindLatency( | 449 if (latency.FindLatency( |
| 434 ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, 0, | 450 ui::INPUT_EVENT_BROWSER_RECEIVED_RENDERER_SWAP_COMPONENT, 0, |
| 435 &browser_swap_component)) { | 451 &browser_swap_component)) { |
| 436 base::TimeDelta delta = | 452 base::TimeDelta delta = |
| 437 gpu_swap_component.event_time - browser_swap_component.event_time; | 453 gpu_swap_begin_component.event_time - browser_swap_component.event_time; |
| 438 browser_composite_latency_history_.InsertSample(delta); | 454 browser_composite_latency_history_.InsertSample(delta); |
| 439 } | 455 } |
| 440 } | 456 } |
| 441 | 457 |
| 442 base::TimeDelta | 458 base::TimeDelta |
| 443 RenderWidgetHostLatencyTracker::GetEstimatedBrowserCompositeTime() const { | 459 RenderWidgetHostLatencyTracker::GetEstimatedBrowserCompositeTime() const { |
| 444 // TODO(brianderson): Remove lower bound on estimate once we're sure it won't | 460 // TODO(brianderson): Remove lower bound on estimate once we're sure it won't |
| 445 // cause regressions. | 461 // cause regressions. |
| 446 return std::max( | 462 return std::max( |
| 447 browser_composite_latency_history_.Percentile( | 463 browser_composite_latency_history_.Percentile( |
| 448 kBrowserCompositeLatencyEstimationPercentile) * | 464 kBrowserCompositeLatencyEstimationPercentile) * |
| 449 kBrowserCompositeLatencyEstimationSlack, | 465 kBrowserCompositeLatencyEstimationSlack, |
| 450 base::TimeDelta::FromMicroseconds( | 466 base::TimeDelta::FromMicroseconds( |
| 451 (1.0f * base::Time::kMicrosecondsPerSecond) / (3.0f * 60))); | 467 (1.0f * base::Time::kMicrosecondsPerSecond) / (3.0f * 60))); |
| 452 } | 468 } |
| 453 | 469 |
| 454 } // namespace content | 470 } // namespace content |
| OLD | NEW |