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
3 // found in the LICENSE file.
4 
5 #include "content/browser/renderer_host/input/render_widget_host_latency_tracker.h"
6 
7 #include <stddef.h>
8 #include <string>
9 
10 #include "base/logging.h"
11 #include "base/metrics/histogram_functions.h"
12 #include "base/metrics/histogram_macros.h"
13 #include "build/build_config.h"
14 #include "content/browser/renderer_host/render_widget_host_delegate.h"
15 #include "content/public/browser/browser_thread.h"
16 #include "content/public/browser/content_browser_client.h"
17 #include "content/public/common/content_client.h"
18 #include "ui/events/blink/web_input_event_traits.h"
19 #include "ui/latency/latency_histogram_macros.h"
20 
21 using blink::WebGestureEvent;
22 using blink::WebInputEvent;
23 using blink::WebMouseEvent;
24 using blink::WebMouseWheelEvent;
25 using blink::WebTouchEvent;
26 using ui::LatencyInfo;
27 
28 namespace content {
29 namespace {
GetTraceNameFromType(blink::WebInputEvent::Type type)30 const char* GetTraceNameFromType(blink::WebInputEvent::Type type) {
31 #define CASE_TYPE(t)        \
32   case WebInputEvent::k##t: \
33     return "InputLatency::" #t
34   switch (type) {
35     CASE_TYPE(Undefined);
36     CASE_TYPE(MouseDown);
37     CASE_TYPE(MouseUp);
38     CASE_TYPE(MouseMove);
39     CASE_TYPE(MouseEnter);
40     CASE_TYPE(MouseLeave);
41     CASE_TYPE(ContextMenu);
42     CASE_TYPE(MouseWheel);
43     CASE_TYPE(RawKeyDown);
44     CASE_TYPE(KeyDown);
45     CASE_TYPE(KeyUp);
46     CASE_TYPE(Char);
47     CASE_TYPE(GestureScrollBegin);
48     CASE_TYPE(GestureScrollEnd);
49     CASE_TYPE(GestureScrollUpdate);
50     CASE_TYPE(GestureFlingStart);
51     CASE_TYPE(GestureFlingCancel);
52     CASE_TYPE(GestureShowPress);
53     CASE_TYPE(GestureTap);
54     CASE_TYPE(GestureTapUnconfirmed);
55     CASE_TYPE(GestureTapDown);
56     CASE_TYPE(GestureTapCancel);
57     CASE_TYPE(GestureDoubleTap);
58     CASE_TYPE(GestureTwoFingerTap);
59     CASE_TYPE(GestureLongPress);
60     CASE_TYPE(GestureLongTap);
61     CASE_TYPE(GesturePinchBegin);
62     CASE_TYPE(GesturePinchEnd);
63     CASE_TYPE(GesturePinchUpdate);
64     CASE_TYPE(TouchStart);
65     CASE_TYPE(TouchMove);
66     CASE_TYPE(TouchEnd);
67     CASE_TYPE(TouchCancel);
68     CASE_TYPE(TouchScrollStarted);
69     CASE_TYPE(PointerDown);
70     CASE_TYPE(PointerUp);
71     CASE_TYPE(PointerMove);
72     CASE_TYPE(PointerRawUpdate);
73     CASE_TYPE(PointerCancel);
74     CASE_TYPE(PointerCausedUaAction);
75   }
76 #undef CASE_TYPE
77   NOTREACHED();
78   return "";
79 }
80 }  // namespace
81 
RenderWidgetHostLatencyTracker(RenderWidgetHostDelegate * delegate)82 RenderWidgetHostLatencyTracker::RenderWidgetHostLatencyTracker(
83     RenderWidgetHostDelegate* delegate)
84     : has_seen_first_gesture_scroll_update_(false),
85       active_multi_finger_gesture_(false),
86       touch_start_default_prevented_(false),
87       render_widget_host_delegate_(delegate) {}
88 
~RenderWidgetHostLatencyTracker()89 RenderWidgetHostLatencyTracker::~RenderWidgetHostLatencyTracker() {}
90 
ComputeInputLatencyHistograms(WebInputEvent::Type type,const LatencyInfo & latency,InputEventAckState ack_result,base::TimeTicks ack_timestamp)91 void RenderWidgetHostLatencyTracker::ComputeInputLatencyHistograms(
92     WebInputEvent::Type type,
93     const LatencyInfo& latency,
94     InputEventAckState ack_result,
95     base::TimeTicks ack_timestamp) {
96   DCHECK(!ack_timestamp.is_null());
97   // If this event was coalesced into another event, ignore it, as the event it
98   // was coalesced into will reflect the full latency.
99   if (latency.coalesced())
100     return;
101 
102   if (latency.source_event_type() == ui::SourceEventType::UNKNOWN ||
103       latency.source_event_type() == ui::SourceEventType::OTHER) {
104     return;
105   }
106 
107   // The event will have gone through OnInputEvent(). So the BEGIN_RWH component
108   // should always be available here.
109   base::TimeTicks rwh_timestamp;
110   bool found_component = latency.FindLatency(
111       ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT, &rwh_timestamp);
112   DCHECK(found_component);
113 
114   bool multi_finger_touch_gesture =
115       WebInputEvent::IsTouchEventType(type) && active_multi_finger_gesture_;
116 
117   bool action_prevented = ack_result == INPUT_EVENT_ACK_STATE_CONSUMED;
118   // Touchscreen tap and scroll gestures depend on the disposition of the touch
119   // start and the current touch. For touch start,
120   // touch_start_default_prevented_ == (ack_result ==
121   // INPUT_EVENT_ACK_STATE_CONSUMED).
122   if (WebInputEvent::IsTouchEventType(type))
123     action_prevented |= touch_start_default_prevented_;
124 
125   std::string event_name = WebInputEvent::GetName(type);
126 
127   if (latency.source_event_type() == ui::SourceEventType::KEY_PRESS) {
128     event_name = "KeyPress";
129   } else if (event_name != "TouchEnd" && event_name != "TouchMove" &&
130              event_name != "TouchStart") {
131     // Only log events we care about (that are documented in histograms.xml),
132     // to avoid using memory and bandwidth for metrics that are not important.
133     return;
134   }
135 
136   std::string default_action_status =
137       action_prevented ? "DefaultPrevented" : "DefaultAllowed";
138 
139   base::TimeTicks main_thread_timestamp;
140   if (latency.FindLatency(ui::INPUT_EVENT_LATENCY_RENDERER_MAIN_COMPONENT,
141                           &main_thread_timestamp)) {
142     if (!multi_finger_touch_gesture) {
143       UMA_HISTOGRAM_INPUT_LATENCY_MILLISECONDS(
144           "Event.Latency.QueueingTime." + event_name + default_action_status,
145           rwh_timestamp, main_thread_timestamp);
146     }
147   }
148 
149   if (!multi_finger_touch_gesture && !main_thread_timestamp.is_null()) {
150     UMA_HISTOGRAM_INPUT_LATENCY_MILLISECONDS(
151         "Event.Latency.BlockingTime." + event_name + default_action_status,
152         main_thread_timestamp, ack_timestamp);
153   }
154 }
155 
OnInputEvent(const blink::WebInputEvent & event,LatencyInfo * latency)156 void RenderWidgetHostLatencyTracker::OnInputEvent(
157     const blink::WebInputEvent& event,
158     LatencyInfo* latency) {
159   DCHECK(latency);
160   DCHECK_CURRENTLY_ON(BrowserThread::UI);
161 
162   OnEventStart(latency);
163 
164   if (event.GetType() == WebInputEvent::kTouchStart) {
165     const WebTouchEvent& touch_event =
166         *static_cast<const WebTouchEvent*>(&event);
167     DCHECK_GE(touch_event.touches_length, static_cast<unsigned>(1));
168     active_multi_finger_gesture_ = touch_event.touches_length != 1;
169   }
170 
171   if (latency->source_event_type() == ui::SourceEventType::KEY_PRESS) {
172     DCHECK(event.GetType() == WebInputEvent::kChar ||
173            event.GetType() == WebInputEvent::kRawKeyDown);
174   }
175 
176   // This is the only place to add the BEGIN_RWH component. So this component
177   // should not already be present in the latency info.
178   bool found_component = latency->FindLatency(
179       ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT, nullptr);
180   DCHECK(!found_component);
181 
182   if (!event.TimeStamp().is_null() &&
183       !latency->FindLatency(ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT,
184                             nullptr)) {
185     base::TimeTicks timestamp_now = base::TimeTicks::Now();
186     base::TimeTicks timestamp_original = event.TimeStamp();
187 
188     // Timestamp from platform input can wrap, e.g. 32 bits timestamp
189     // for Xserver and Window MSG time will wrap about 49.6 days. Do a
190     // sanity check here and if wrap does happen, use TimeTicks::Now()
191     // as the timestamp instead.
192     if ((timestamp_now - timestamp_original).InDays() > 0)
193       timestamp_original = timestamp_now;
194 
195     latency->AddLatencyNumberWithTimestamp(
196         ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT, timestamp_original);
197   }
198 
199   latency->AddLatencyNumberWithTraceName(
200       ui::INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
201       GetTraceNameFromType(event.GetType()));
202 
203   if (event.GetType() == blink::WebInputEvent::kGestureScrollBegin) {
204     has_seen_first_gesture_scroll_update_ = false;
205   } else if (event.GetType() == blink::WebInputEvent::kGestureScrollUpdate) {
206     // Make a copy of the INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT with a
207     // different name INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT.
208     // So we can track the latency specifically for scroll update events.
209     base::TimeTicks original_event_timestamp;
210     if (latency->FindLatency(ui::INPUT_EVENT_LATENCY_ORIGINAL_COMPONENT,
211                              &original_event_timestamp)) {
212       latency->AddLatencyNumberWithTimestamp(
213           has_seen_first_gesture_scroll_update_
214               ? ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_ORIGINAL_COMPONENT
215               : ui::INPUT_EVENT_LATENCY_FIRST_SCROLL_UPDATE_ORIGINAL_COMPONENT,
216           original_event_timestamp);
217       latency->AddLatencyNumberWithTimestamp(
218           ui::INPUT_EVENT_LATENCY_SCROLL_UPDATE_LAST_EVENT_COMPONENT,
219           original_event_timestamp);
220     }
221 
222     has_seen_first_gesture_scroll_update_ = true;
223     latency->set_scroll_update_delta(
224         static_cast<const WebGestureEvent&>(event).data.scroll_update.delta_y);
225     latency->set_predicted_scroll_update_delta(
226         static_cast<const WebGestureEvent&>(event).data.scroll_update.delta_y);
227   }
228 }
229 
OnInputEventAck(const blink::WebInputEvent & event,LatencyInfo * latency,InputEventAckState ack_result)230 void RenderWidgetHostLatencyTracker::OnInputEventAck(
231     const blink::WebInputEvent& event,
232     LatencyInfo* latency, InputEventAckState ack_result) {
233   DCHECK(latency);
234 
235   // Latency ends if an event is acked but does not cause render scheduling.
236   bool rendering_scheduled = latency->FindLatency(
237       ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_MAIN_COMPONENT, nullptr);
238   rendering_scheduled |= latency->FindLatency(
239       ui::INPUT_EVENT_LATENCY_RENDERING_SCHEDULED_IMPL_COMPONENT, nullptr);
240 
241   if (WebInputEvent::IsTouchEventType(event.GetType())) {
242     const WebTouchEvent& touch_event =
243         *static_cast<const WebTouchEvent*>(&event);
244     if (event.GetType() == WebInputEvent::kTouchStart) {
245       touch_start_default_prevented_ =
246           ack_result == INPUT_EVENT_ACK_STATE_CONSUMED;
247     } else if (event.GetType() == WebInputEvent::kTouchEnd ||
248                event.GetType() == WebInputEvent::kTouchCancel) {
249       active_multi_finger_gesture_ = touch_event.touches_length > 2;
250     }
251   }
252 
253   // If this event couldn't have caused a gesture event, and it didn't trigger
254   // rendering, we're done processing it. If the event got coalesced then
255   // terminate it as well. We also exclude cases where we're against the scroll
256   // extent from scrolling metrics.
257   if (!rendering_scheduled || latency->coalesced() ||
258       (event.GetType() == WebInputEvent::kGestureScrollUpdate &&
259        ack_result == INPUT_EVENT_ACK_STATE_NO_CONSUMER_EXISTS)) {
260     latency->Terminate();
261   }
262 
263   ComputeInputLatencyHistograms(event.GetType(), *latency, ack_result,
264                                 base::TimeTicks::Now());
265 }
266 
OnEventStart(ui::LatencyInfo * latency)267 void RenderWidgetHostLatencyTracker::OnEventStart(ui::LatencyInfo* latency) {
268   static uint64_t global_trace_id = 0;
269   latency->set_trace_id(++global_trace_id);
270   latency->set_ukm_source_id(
271       render_widget_host_delegate_->GetUkmSourceIdForLastCommittedSource());
272 }
273 
274 }  // namespace content
275