Report LatencyInfo through trace buffer

Report LatencyInfo through trace buffer

This CL is the first step in converting to use trace event to
collect LatencyInfo. Changes are:

1. Each LatencyInfo will have at most one BEGIN/TERMINATED component.
When the BEGIN component is added, an ASYNC_BEGIN trace event is issued.
When the TERMINATED component is added, an ASYNC_END trace event is issued,
and the LatencyInfo is dumped into the trace buffer.

2. BEGIN component is added to event's LatencyInfo when the event reaches RWH.

3. If events cause renderering to be schedueld in renderer, then the
INPUT_EVENT_LATENCY_TERMINATED_FRAME_SWAP_COMPONENT
is added when actual frame swap happens. Accordingly, swap_timestamp_ is
removed.

4. If events do not cause rendering to be scheduled in renderer, then
   4.1) INPUT_EVENT_LATENCY_TERMINATED_MOUSE/GESTURE_COMPONENT
        is added when the mouse/gesture events are acked from renderer.
   4.2) If the acked touch event become gesture event, touch event's
        LatencInfo are copied into gesture event's LatencyInfo.
   4.3) If the acked touch event does not become gesture event,
        INPUT_EVENT_LATENCY_TERMINATED_TOUCH_COMPONENT
        is then added to the touch event's LatencyInfo.

This CL is only adding the ability to dump LatencyInfo to trace buffer but don't
change the current way LatencyInfo is used so all the telemetry tests are not
affected. The complete migration will be in followup CLs.

BUG=BUG=246034
TEST=1. telemetry smoothness test still works.
2. Do trace recording with category "benchmark", check that latencyinfo are
dumped to "InputLatency";

Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=228095

[Yufeng Shen (Slow to review), 2013-09-27 23:42:01]

John, Nat:

This is the first step towards latency measurement API V2.
It is small enough for a quick review. PTAL.

[nduca, 2013-10-01 21:43:44]

the rough shape of this looks solid. can we have jdduke look through the input
stuff? 

some comments below

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc
File ui/events/latency_info.cc (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:62: void LatencyInfo::Report(LatencyComponentType
terminal_component) {
lets try putting the logic here inside the AddLatencyNumber code

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:64: TRACE_EVENT_INSTANT1("benchmark",
can you try to issue async_begin and async_end traces and see what happens

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:78: base::StringPrintf("%ld %ld %d",
this should probably be another dict inside instad of a stringprintf, e.g.

component_info = new DictionaryValue();
component_info->SetString("seq_number", it->first.second);
...

record_data->Set(GetComponetnname(), component_info);

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h
File ui/events/latency_info.h (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:20: class LatencyInfoTracedValue : public
base::debug::ConvertableToTraceFormat {
i think you can put this implementation in the cc file since its not visible
elsewhere

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:39: INPUT_EVENT_LATENCY_RWH_COMPONENT,
lets prefix this with a name to indicate that it begins the flow

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:54: INPUT_EVENT_LATENCY_ACKED_MOUSE_COMPONENT,
lets try calling these FINISH_ or TERMINAL ... latency_finished_at_blahblah for
example

[jdduke (slow), 2013-10-01 23:45:31]

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
File content/browser/renderer_host/input/touch_event_queue.cc (right):

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/input/touch_event_queue.cc:200: ui::LatencyInfo*
latency = const_cast<ui::LatencyInfo*>(&(iter->latency));
Sorry, this isn't directly related to your patch, but this const_cast kills me,
could you go ahead and just make this a regular iterator?  You can change
CoalescedWebTouchEvent to return an iterator(), I believe this is the only place
we use it.

Bonus points for getting rid of begin()/end() calls entirely, and adding a
CoalescedWebTouchEvent::DispatchAckTo(client, renderer_latency_info, ack_result)
that does the dispatch there =/

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2189: const
MouseWheelEventWithLatencyInfo& event,
See my comment below about making Report() const.  That will eliminate some of
the LatencyInfo copying.

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2215: ui::LatencyInfo*
latency = const_cast<ui::LatencyInfo*>(&(event.latency));
Again, if Report() was const we could do away with the const_cast here.

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2542:
ui::LatencyInfo::LatencyComponent rwh_component;
Hmm, I thought we had moved these calculations/updates
(ComputeTouchLatency/FrameSwapped) to the BrowserRenderingStats object? Maybe
that was a separate patch?

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h
File ui/events/latency_info.h (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:89: scoped_ptr<base::debug::ConvertableToTraceFormat>
AsTraceableData() const;
AsTraceableData() appears to be used only be Report().  Could you make make it a
static/scoped method inside latency_info.cc?  Or make it private? You could then
have it take the "terminal" latency component as an argument, which in turn
would allow you to make Report(...) const, perhaps something like

AsTraceableData(const LatencyInfo& latency, LatencyComponentType
terminal_component);

[Rick Byers, 2013-10-03 13:12:41]

Thanks Yufeng, this looks like a great step in the right direction!

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc
File ui/events/latency_info.cc (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:62: void LatencyInfo::Report(LatencyComponentType
terminal_component) {
It should be illegal to call Report more than once for a given LatencyInfo,
right?  Otherwise we risk skewing the results by double-counting some components
but not others.  Can you enforce that here (poisoning the instance somehow that
will cause a CHECK failure if it's used further)?

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h
File ui/events/latency_info.h (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:54: INPUT_EVENT_LATENCY_ACKED_MOUSE_COMPONENT,
On 2013/10/01 21:43:44, nduca wrote:
> lets try calling these FINISH_ or TERMINAL ... latency_finished_at_blahblah
for
> example 

Is the idea that these will always be terminal?  Won't even the common case of
touch scrolling have a ACKED_TOUCH, ACKED_GESTURE AND a FRAME_SWAP?

[Yufeng Shen (Slow to review), 2013-10-04 00:29:50]

Enforce that event's LatencyInfo will have at most one
begin component and one terminal component. And the LatencyInfo
is dumped into trace buffer when the terminal component is added.

PTAL.

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
File content/browser/renderer_host/input/touch_event_queue.cc (right):

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/input/touch_event_queue.cc:200: ui::LatencyInfo*
latency = const_cast<ui::LatencyInfo*>(&(iter->latency));
On 2013/10/01 23:45:31, jdduke wrote:
> Sorry, this isn't directly related to your patch, but this const_cast kills
me,
> could you go ahead and just make this a regular iterator?  You can change
> CoalescedWebTouchEvent to return an iterator(), I believe this is the only
place
> we use it.

Done.

> 
> Bonus points for getting rid of begin()/end() calls entirely, and adding a
> CoalescedWebTouchEvent::DispatchAckTo(client, renderer_latency_info,
ack_result)
> that does the dispatch there =/

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2189: const
MouseWheelEventWithLatencyInfo& event,
On 2013/10/01 23:45:31, jdduke wrote:
> See my comment below about making Report() const.  That will eliminate some of
> the LatencyInfo copying.

As to Nat's suggestion, removed the Report() function and move the logic into
AddLatencyNumber(component_type) that if the component_type is terminal
component, dump the latency info into trace buffer. AddLatencyNumber() is
non-const so I change the OnXXXEventAck() signature to be 
OnXXXEventAck(WebXXXEevet, ack_result, ui::LatencyInfo* latency)

so we can call latency->AddLatencyNumber().

Bundling const WebInputEvent with non-const latencyinfo into one const
XXXEventWithLatencyInfo is causing all the constness/copying problem. So
separate them.

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2215: ui::LatencyInfo*
latency = const_cast<ui::LatencyInfo*>(&(event.latency));
On 2013/10/01 23:45:31, jdduke wrote:
> Again, if Report() was const we could do away with the const_cast here.

ditto

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2542:
ui::LatencyInfo::LatencyComponent rwh_component;
On 2013/10/01 23:45:31, jdduke wrote:
> Hmm, I thought we had moved these calculations/updates
> (ComputeTouchLatency/FrameSwapped) to the BrowserRenderingStats object? Maybe
> that was a separate patch?

Yeah, I wasn't able to land that. But eventually we will get rid of this
function entirely once we convert to the trace base approach: whenever we think
the latencyinfo is done we dump the latencyinfo into trace buffer and we can in
telemetry gather these latencyinfo and do analysis on them.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc
File ui/events/latency_info.cc (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:62: void LatencyInfo::Report(LatencyComponentType
terminal_component) {
On 2013/10/01 21:43:44, nduca wrote:
> lets try putting the logic here inside the AddLatencyNumber code

Done.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:62: void LatencyInfo::Report(LatencyComponentType
terminal_component) {
On 2013/10/03 13:12:41, Rick Byers wrote:
> It should be illegal to call Report more than once for a given LatencyInfo,
> right?  Otherwise we risk skewing the results by double-counting some
components
> but not others.  Can you enforce that here (poisoning the instance somehow
that
> will cause a CHECK failure if it's used further)?

Yes, added DCHECK to enforce that at most only one begin/terminal
component is allowed to be added.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:64: TRACE_EVENT_INSTANT1("benchmark",
On 2013/10/01 21:43:44, nduca wrote:
> can you try to issue async_begin and async_end traces and see what happens

Yes, we can see the grey latency rect in tracing UI after using
TRACE_EVENT_ASYNC_BEGIN/END.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.cc#new...
ui/events/latency_info.cc:78: base::StringPrintf("%ld %ld %d",
On 2013/10/01 21:43:44, nduca wrote:
> this should probably be another dict inside instad of a stringprintf, e.g.
> 
> component_info = new DictionaryValue();
> component_info->SetString("seq_number", it->first.second);
> ...
> 
> record_data->Set(GetComponetnname(), component_info);

Done.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h
File ui/events/latency_info.h (right):

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:20: class LatencyInfoTracedValue : public
base::debug::ConvertableToTraceFormat {
On 2013/10/01 21:43:44, nduca wrote:
> i think you can put this implementation in the cc file since its not visible
> elsewhere

Done.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:39: INPUT_EVENT_LATENCY_RWH_COMPONENT,
On 2013/10/01 21:43:44, nduca wrote:
> lets prefix this with a name to indicate that it begins the flow

Done.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:54: INPUT_EVENT_LATENCY_ACKED_MOUSE_COMPONENT,
On 2013/10/01 21:43:44, nduca wrote:
> lets try calling these FINISH_ or TERMINAL ... latency_finished_at_blahblah
for
> example 

Done.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:54: INPUT_EVENT_LATENCY_ACKED_MOUSE_COMPONENT,
On 2013/10/03 13:12:41, Rick Byers wrote:
> On 2013/10/01 21:43:44, nduca wrote:
> > lets try calling these FINISH_ or TERMINAL ... latency_finished_at_blahblah
> for
> > example 
> 
> Is the idea that these will always be terminal?  Won't even the common case of
> touch scrolling have a ACKED_TOUCH, ACKED_GESTURE AND a FRAME_SWAP?  

As offline talk, we will only allow one terminal component.
so for a touch event. See the comments in the new patch.

https://codereview.chromium.org/25022003/diff/1/ui/events/latency_info.h#newc...
ui/events/latency_info.h:89: scoped_ptr<base::debug::ConvertableToTraceFormat>
AsTraceableData() const;
On 2013/10/01 23:45:31, jdduke wrote:
> AsTraceableData() appears to be used only be Report().  Could you make make it
a
> static/scoped method inside latency_info.cc?  Or make it private? You could
then
> have it take the "terminal" latency component as an argument, which in turn
> would allow you to make Report(...) const, perhaps something like
> 
> AsTraceableData(const LatencyInfo& latency, LatencyComponentType
> terminal_component);

moved into cc file as a global function.

[WRONG-USE-chromium, 2013-10-04 01:43:42]

https://codereview.chromium.org/25022003/diff/24001/ui/events/latency_info.cc
File ui/events/latency_info.cc (right):

https://codereview.chromium.org/25022003/diff/24001/ui/events/latency_info.cc...
ui/events/latency_info.cc:151: TRACE_EVENT_ASYNC_BEGIN0("benchmark",
If MergeWith is called, then we'll have a lot of dangling (BEGIN but no END)
trace records, right?  Is that a problem?  I know the plan is to eventually
eliminate MergeWith...

https://codereview.chromium.org/25022003/diff/24001/ui/events/latency_info.cc...
ui/events/latency_info.cc:161: DCHECK(!terminated);
Since we don't normally run perf tests on Debug builds, can you make this a
CHECK instead?

[jdduke (slow), 2013-10-04 02:22:18]

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2215: ui::LatencyInfo*
latency = const_cast<ui::LatencyInfo*>(&(event.latency));
On 2013/10/04 00:29:51, Yufeng Shen wrote:
> On 2013/10/01 23:45:31, jdduke wrote:
> > Again, if Report() was const we could do away with the const_cast here.
> 
> ditto

Sorry, I didn't mean to say we should start passing non-const ui::LatencyInfo
pointers around.  I was more so wondering why in
OnWheelEventAck/OnGestureEventAck you copied the ui::LatencyInfo, but in
OnGestureEventAck you were modifying it in-place?  I was fine with the copying
before, it was really just the const_cast'ing =/

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
File content/browser/renderer_host/input/immediate_input_router.cc (right):

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:537: ack_result,
Are we not using the current_wheel_event_.latency in any way?

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
File content/browser/renderer_host/input/touch_event_queue.cc (right):

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
content/browser/renderer_host/input/touch_event_queue.cc:126: ui::LatencyInfo*
latency_info) {
It looks like you can keep this a const ref, same with the
PopTouchEventToClient() arg.

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
content/browser/renderer_host/input/touch_event_queue.cc:190: if
(touch_queue_.empty())
You're adding renderer_latency_info to latency below, so I think you can keep it
const ref.

[Yufeng Shen (Slow to review), 2013-10-04 18:03:02]

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/1/content/browser/renderer_host...
content/browser/renderer_host/render_widget_host_impl.cc:2215: ui::LatencyInfo*
latency = const_cast<ui::LatencyInfo*>(&(event.latency));
On 2013/10/04 02:22:19, jdduke wrote:
> On 2013/10/04 00:29:51, Yufeng Shen wrote:
> > On 2013/10/01 23:45:31, jdduke wrote:
> > > Again, if Report() was const we could do away with the const_cast here.
> > 
> > ditto
> 
> Sorry, I didn't mean to say we should start passing non-const ui::LatencyInfo
> pointers around.  I was more so wondering why in
> OnWheelEventAck/OnGestureEventAck you copied the ui::LatencyInfo, but in
> OnGestureEventAck you were modifying it in-place?  I was fine with the copying
> before, it was really just the const_cast'ing =/ 

So in the new patch I switch to passing both const WebInputEvent& and
ui::LatencyInfo* for all onGesture/Wheel/TouchEventAck. 
The main problem is that we need to call a non-const method on LatencyInfo
but the XXXEventWithLatencyInfo is passed around as const&, so either
I do a copy of the LatencyInfo and call the non-const method on the copy
or I separate the LatencyInfo from the WebInputEvent and directly call
the non-const method on the ui::LatencyInfo*

Though either way is perfect :(

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
File content/browser/renderer_host/input/immediate_input_router.cc (right):

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:537: ack_result,
On 2013/10/04 02:22:19, jdduke wrote:
> Are we not using the current_wheel_event_.latency in any way?

Ideally I would like to have each uncoalesced mouse wheel event's
latencyinfo combined with renderer side latencyinfo then add terminal
component to it. 
I added a TODO for when we have uncoalesced mouse event cached.

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
File content/browser/renderer_host/input/touch_event_queue.cc (right):

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
content/browser/renderer_host/input/touch_event_queue.cc:126: ui::LatencyInfo*
latency_info) {
On 2013/10/04 02:22:19, jdduke wrote:
> It looks like you can keep this a const ref, same with the
> PopTouchEventToClient() arg.

Done.

https://codereview.chromium.org/25022003/diff/24001/content/browser/renderer_...
content/browser/renderer_host/input/touch_event_queue.cc:190: if
(touch_queue_.empty())
On 2013/10/04 02:22:19, jdduke wrote:
> You're adding renderer_latency_info to latency below, so I think you can keep
it
> const ref.

Done.

https://codereview.chromium.org/25022003/diff/24001/ui/events/latency_info.cc
File ui/events/latency_info.cc (right):

https://codereview.chromium.org/25022003/diff/24001/ui/events/latency_info.cc...
ui/events/latency_info.cc:151: TRACE_EVENT_ASYNC_BEGIN0("benchmark",
On 2013/10/04 01:43:43, rbyers wrote:
> If MergeWith is called, then we'll have a lot of dangling (BEGIN but no END)
> trace records, right?  Is that a problem?  I know the plan is to eventually
> eliminate MergeWith...

Ideally we would like to totally get rid of MergeWith. The only place I am
worrying about now is when we coalescing events. The coalesced event will be
sent to renderer and can end there, so what should be the latencyinfo for
the coalesced event ?

If the the coalesced event does not end at renderer side and gets acked back,
as long as we keep all the uncoalesced events, we can still call END for each
of them.

https://codereview.chromium.org/25022003/diff/24001/ui/events/latency_info.cc...
ui/events/latency_info.cc:161: DCHECK(!terminated);
On 2013/10/04 01:43:43, rbyers wrote:
> Since we don't normally run perf tests on Debug builds, can you make this a
> CHECK instead?

Done.

[jbauman, 2013-10-08 07:09:45]

lgtm

[jdduke (slow), 2013-10-08 16:28:07]

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
File content/browser/renderer_host/input/immediate_input_router.cc (right):

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:432:
ui::LatencyInfo latency_info) {
So, we're copying the ui::LatencyInfo here, only to pass a pointer to it... that
would be fine if the modification is done inside the ImmediateInputRouter, but
it looks like the only modifier is |ack_handler_|.  I hate to do this, but could
you please undo all the arg modifications here in the ImmediateInputRouter and
in the InputAckHandler, and go back to the previous model, passing by const ref?
 If you're going to have to make a copy somewhere, I'd prefer it be as close as
possible to the place where the copy is required
(RenderWidgetHostImpl::On*EventAck, and only when it has the necessary
components that warrant a copy).

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2197:
latency->AddLatencyNumber(
Please revert the arg changes and just copy the ui::LatencyInfo if necessary
here (within the if).

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2210: ui::LatencyInfo*
latency) {
Same as above.

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2232:
latency->AddLatencyNumber(ui::INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT,
Ditto.

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
File content/browser/renderer_host/render_widget_host_impl.h (right):

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.h:755: ui::LatencyInfo*
latency) OVERRIDE;
Please undo these arg changes.

[Yufeng Shen (Slow to review), 2013-10-08 19:35:58]

add OWNERS:

sadrul@ : content/browser/renderer_host/*
          ui/events/*

jln@ : content/common/*

apatrick: ui/surface/*

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
File content/browser/renderer_host/input/immediate_input_router.cc (right):

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:432:
ui::LatencyInfo latency_info) {
On 2013/10/08 16:28:08, jdduke wrote:
> So, we're copying the ui::LatencyInfo here, only to pass a pointer to it...
that
> would be fine if the modification is done inside the ImmediateInputRouter, but
> it looks like the only modifier is |ack_handler_|.  I hate to do this, but
could
> you please undo all the arg modifications here in the ImmediateInputRouter and
> in the InputAckHandler, and go back to the previous model, passing by const
ref?
>  If you're going to have to make a copy somewhere, I'd prefer it be as close
as
> possible to the place where the copy is required
> (RenderWidgetHostImpl::On*EventAck, and only when it has the necessary
> components that warrant a copy). 

Done.

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2197:
latency->AddLatencyNumber(
On 2013/10/08 16:28:08, jdduke wrote:
> Please revert the arg changes and just copy the ui::LatencyInfo if necessary
> here (within the if).

Done.

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2210: ui::LatencyInfo*
latency) {
On 2013/10/08 16:28:08, jdduke wrote:
> Same as above.

Done.

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2232:
latency->AddLatencyNumber(ui::INPUT_EVENT_LATENCY_ACKED_TOUCH_COMPONENT,
On 2013/10/08 16:28:08, jdduke wrote:
> Ditto.

Done.

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
File content/browser/renderer_host/render_widget_host_impl.h (right):

https://codereview.chromium.org/25022003/diff/37001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.h:755: ui::LatencyInfo*
latency) OVERRIDE;
On 2013/10/08 16:28:08, jdduke wrote:
> Please undo these arg changes.

Done.

[jdduke (slow), 2013-10-08 20:58:49]

content/browser/renderer_host/input lgtm, modulo a few nits and a rebase.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
File content/browser/renderer_host/input/immediate_input_router.cc (right):

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:361:
ui::LatencyInfo renderer_latency;
Why not use the original |latency_info| as before?

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:530:
mouse_wheel_pending_ = false;
Could you move |mouse_wheel_pending_ = false| down right below
|ack_handler_->OnWheelEventAck()|? That way, if the ack queues an additional
WheelEvent, we're not overwriting |current_wheel_event_|. Thanks.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:534:
ui::LatencyInfo combined_latency = current_wheel_event_.latency;
I don't think you need the temporary |combined_latency| here.  Just operate on
|current_wheeL_event_.latency| in-place, e.g.,
current_wheel_event_.latency.AddNewLatencyFrom(latency), then pass
|current_wheel_event_| to OnWheelEventAck().  It will be overwritten whenever
the next wheel event is sent, so it's fine to mutate it here.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:557: // event
event and add terminal component to each of them.
You'll need to rebase to crrev.com/26376002 after it lands.  Just add a
ui::LatencyInfo parameter to |gesture_event_filter_->ProcessGestureAck()|, and
inside the GEF you can |AddNewLatencyFrom(latency)| to the coalesced gesture
that's getting acked.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2192: if
(!wheel_event.latency.FindLatency(
In the future, we might consider an additional
ui::LatencyInfo::ReportTerminalComponent(...) that reports with the provided
terminal component and doesn't mutate the latency.  This would be for occasions
like this method where we're done with the latency and just want to report it. 
That can come later, and may not even be needed when these OnFooEventAck()
methods start taking scoped_ptrs.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2229: // TouchEvent
latency does not end when acked since it could later on
Nit: You might as well copy |event| into a new TouchEventWithLatencyInfo,
operate on that latency, then pass it to the view, rather than copying the
latency, then copying it and the event to a new TouchEventWithLatencyInfo below.

[jln (very slow on Chromium), 2013-10-08 21:18:05]

Sorry, you need a content/ OWNER for content/common.

[Yufeng Shen (Slow to review), 2013-10-08 21:35:17]

-jln@ +jam@  for OWNER of content/common/*

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
File content/browser/renderer_host/input/immediate_input_router.cc (right):

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:361:
ui::LatencyInfo renderer_latency;
On 2013/10/08 20:58:50, jdduke wrote:
> Why not use the original |latency_info| as before?

right. forgot to clean this. done.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:530:
mouse_wheel_pending_ = false;
On 2013/10/08 20:58:50, jdduke wrote:
> Could you move |mouse_wheel_pending_ = false| down right below
> |ack_handler_->OnWheelEventAck()|? That way, if the ack queues an additional
> WheelEvent, we're not overwriting |current_wheel_event_|. Thanks.

Done.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/input/immediate_input_router.cc:534:
ui::LatencyInfo combined_latency = current_wheel_event_.latency;
On 2013/10/08 20:58:50, jdduke wrote:
> I don't think you need the temporary |combined_latency| here.  Just operate on
> |current_wheeL_event_.latency| in-place, e.g.,
> current_wheel_event_.latency.AddNewLatencyFrom(latency), then pass
> |current_wheel_event_| to OnWheelEventAck().  It will be overwritten whenever
> the next wheel event is sent, so it's fine to mutate it here.

Done.

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
File content/browser/renderer_host/render_widget_host_impl.cc (right):

https://codereview.chromium.org/25022003/diff/60001/content/browser/renderer_...
content/browser/renderer_host/render_widget_host_impl.cc:2229: // TouchEvent
latency does not end when acked since it could later on
On 2013/10/08 20:58:50, jdduke wrote:
> Nit: You might as well copy |event| into a new TouchEventWithLatencyInfo,
> operate on that latency, then pass it to the view, rather than copying the
> latency, then copying it and the event to a new TouchEventWithLatencyInfo
below.

Done.

[sadrul, 2013-10-09 19:23:26]

Mostly nits.

miletus@, jdduke@: Should/Can all the latency-info related code be moved out of
RenderWidgetHostImpl and into IIR? (not part of this CL, of course)

https://codereview.chromium.org/25022003/diff/71001/ui/events/gestures/gestur...
File ui/events/gestures/gesture_sequence.cc (right):

https://codereview.chromium.org/25022003/diff/71001/ui/events/gestures/gestur...
ui/events/gestures/gesture_sequence.cc:618: }
Please move this block of code into a separate independent function (e.g.
UpdateGestureEventLatencyInfo). This code should probably live elsewhere, since
the GR seems like an odd place for this. Moving to a separate function will
allow to move this out when there's a better place for this.

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc
File ui/events/latency_info.cc (right):

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
ui/events/latency_info.cc:51: return false;
return type == ui::...

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
ui/events/latency_info.cc:58: base::Value* value);
Can this be scoped_ptr<base::Value> too, to clarify ownership?

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
ui/events/latency_info.cc:76: return
result.PassAs<base::debug::ConvertableToTraceFormat>();
You can just do:
  return scoped_ptr<base::debug::...>(new ....());

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
ui/events/latency_info.cc:149: CHECK(trace_id == -1);
CHECK_EQ(-1, trace_id)

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
ui/events/latency_info.cc:176: LatencyMap::iterator it =
latency_components.find(key);
Shouldn't the checks above be in here (since this can be directly called from
outside)?

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.h
File ui/events/latency_info.h (right):

https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.h#...
ui/events/latency_info.h:21: INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
Maybe match the comment and just call this I_E_L_BEGIN_COMPONENT?

[Yufeng Shen (Slow to review), 2013-10-09 20:53:39]

On 2013/10/09 19:23:26, sadrul wrote:
> Mostly nits.
> 
> miletus@, jdduke@: Should/Can all the latency-info related code be moved out
of
> RenderWidgetHostImpl and into IIR? (not part of this CL, of course)
> 

Yes. Mainly there are 3 parts of latency-info related code:
1) Adding latencyinfo to WebInputEvents. I think this can be done in IIR.
2) LatencyInfo check on event ack. RWHI is inheriting from InputAckHandler, so I
guess
   these code will stay in RWHI as part of the event ack processing.
3) Latency stats computation when swap buffer message is received in RWHI. We
are converting
   to dump latency info into trace buffer and do analysis in telemetry. So these
part of latency
   stats analysis code will be gone soon.

>
https://codereview.chromium.org/25022003/diff/71001/ui/events/gestures/gestur...
> File ui/events/gestures/gesture_sequence.cc (right):
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/gestures/gestur...
> ui/events/gestures/gesture_sequence.cc:618: }
> Please move this block of code into a separate independent function (e.g.
> UpdateGestureEventLatencyInfo). This code should probably live elsewhere,
since
> the GR seems like an odd place for this. Moving to a separate function will
> allow to move this out when there's a better place for this.
> 
> https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc
> File ui/events/latency_info.cc (right):
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
> ui/events/latency_info.cc:51: return false;
> return type == ui::...
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
> ui/events/latency_info.cc:58: base::Value* value);
> Can this be scoped_ptr<base::Value> too, to clarify ownership?
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
> ui/events/latency_info.cc:76: return
> result.PassAs<base::debug::ConvertableToTraceFormat>();
> You can just do:
>   return scoped_ptr<base::debug::...>(new ....());
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
> ui/events/latency_info.cc:149: CHECK(trace_id == -1);
> CHECK_EQ(-1, trace_id)
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.cc...
> ui/events/latency_info.cc:176: LatencyMap::iterator it =
> latency_components.find(key);
> Shouldn't the checks above be in here (since this can be directly called from
> outside)?
> 
> https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.h
> File ui/events/latency_info.h (right):
> 
>
https://codereview.chromium.org/25022003/diff/71001/ui/events/latency_info.h#...
> ui/events/latency_info.h:21: INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
> Maybe match the comment and just call this I_E_L_BEGIN_COMPONENT?

[Yufeng Shen (Slow to review), 2013-10-09 20:53:49]

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/gestures...
File ui/events/gestures/gesture_sequence.cc (right):

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/gestures...
ui/events/gestures/gesture_sequence.cc:618: }
On 2013/10/09 19:23:27, sadrul wrote:
> Please move this block of code into a separate independent function (e.g.
> UpdateGestureEventLatencyInfo). This code should probably live elsewhere,
since
> the GR seems like an odd place for this. Moving to a separate function will
> allow to move this out when there's a better place for this.

Done.

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
File ui/events/latency_info.cc (right):

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
ui/events/latency_info.cc:51: return false;
On 2013/10/09 19:23:27, sadrul wrote:
> return type == ui::...

Done.

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
ui/events/latency_info.cc:58: base::Value* value);
On 2013/10/09 19:23:27, sadrul wrote:
> Can this be scoped_ptr<base::Value> too, to clarify ownership?

Done.

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
ui/events/latency_info.cc:76: return
result.PassAs<base::debug::ConvertableToTraceFormat>();
On 2013/10/09 19:23:27, sadrul wrote:
> You can just do:
>   return scoped_ptr<base::debug::...>(new ....());

Done.

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
ui/events/latency_info.cc:149: CHECK(trace_id == -1);
On 2013/10/09 19:23:27, sadrul wrote:
> CHECK_EQ(-1, trace_id)

Done.

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
ui/events/latency_info.cc:176: LatencyMap::iterator it =
latency_components.find(key);
On 2013/10/09 19:23:27, sadrul wrote:
> Shouldn't the checks above be in here (since this can be directly called from
> outside)?

right, done.

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
File ui/events/latency_info.h (right):

https://chromiumcodereview.appspot.com/25022003/diff/71001/ui/events/latency_...
ui/events/latency_info.h:21: INPUT_EVENT_LATENCY_BEGIN_RWH_COMPONENT,
On 2013/10/09 19:23:27, sadrul wrote:
> Maybe match the comment and just call this I_E_L_BEGIN_COMPONENT?

oh, here by BEGIN COMPONENT I meant it is contrast to TERMINAL
component. I think keep RWH there is more clear so we this begin
component is added in RWH.

[jdduke (slow), 2013-10-09 22:43:25]

On 2013/10/09 19:23:26, sadrul wrote:
> Mostly nits.
> 
> miletus@, jdduke@: Should/Can all the latency-info related code be moved out
of
> RenderWidgetHostImpl and into IIR? (not part of this CL, of course)

Yes.  That's how it was originally but I moved it back out in anticipation of
the BIR.

[jam, 2013-10-10 05:00:48]

On 2013/10/08 21:35:17, Yufeng Shen wrote:
> -jln@ +jam@  for OWNER of content/common/*
> 
lgtm

[stuartmorgan, 2013-10-10 20:28:00]

surface/ LGTM

[Ken Russell (switch to Gerrit), 2013-10-10 21:18:24]

ui/surface/ LGTM

[sadrul, 2013-10-10 21:58:37]

LGTM with a couple of comments

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/gestures...
File ui/events/gestures/gesture_sequence.cc (right):

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/gestures...
ui/events/gestures/gesture_sequence.cc:1233: void
GestureSequence::UpdateGestureEventLatencyInfo(const TouchEvent& event,
Move this into an independent function in the anonymous namespace.

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/latency_...
File ui/events/latency_info.h (right):

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/latency_...
ui/events/latency_info.h:97: bool dump_to_trace);
Adding a boolean param like this in a public API is discouraged. You would
normally add an enum here instead.

I think LatencyInfo can be cleaned up farther:
 * Hide the member variables.
 * Introduce an internal AddLatencyNumberWithTimestampInternal, that takes in
the bool parameter, and call into that from the public APIs with the appropriate
enum/bool value.
 * Make this a class

This cleanup can happen in a follow-up CL. And if this is cleaned up soon, then
the bool param in this CL should be OK.

[ernstm, 2013-10-10 22:27:15]

Given that the LatencyInfo trace events will be consumed by telemetry
benchmarks, I recommend putting the calls that issue these events into a
separate file with a limited number of per-file OWNERS. With rendering
benchmarks we made the experience that people change event/parameter names and
that breaks the benchmarks. You can take a look at
cc/debug/benchmark_instrumentation for an example of how to do that (the latest
change is currently under review here:
https://codereview.chromium.org/25353009/).

[Yufeng Shen (Slow to review), 2013-10-10 22:52:04]

On 2013/10/10 22:27:15, Manfred Ernst wrote:
> Given that the LatencyInfo trace events will be consumed by telemetry
> benchmarks, I recommend putting the calls that issue these events into a
> separate file with a limited number of per-file OWNERS. With rendering
> benchmarks we made the experience that people change event/parameter names and
> that breaks the benchmarks. You can take a look at
> cc/debug/benchmark_instrumentation for an example of how to do that (the
latest
> change is currently under review here:
> https://codereview.chromium.org/25353009/).

Right. Will do it in a follow-up CL.

[Yufeng Shen (Slow to review), 2013-10-10 22:52:14]

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/gestures...
File ui/events/gestures/gesture_sequence.cc (right):

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/gestures...
ui/events/gestures/gesture_sequence.cc:1233: void
GestureSequence::UpdateGestureEventLatencyInfo(const TouchEvent& event,
On 2013/10/10 21:58:38, sadrul wrote:
> Move this into an independent function in the anonymous namespace.

Done.

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/latency_...
File ui/events/latency_info.h (right):

https://chromiumcodereview.appspot.com/25022003/diff/80001/ui/events/latency_...
ui/events/latency_info.h:97: bool dump_to_trace);
On 2013/10/10 21:58:38, sadrul wrote:
> Adding a boolean param like this in a public API is discouraged. You would
> normally add an enum here instead.
> 
> I think LatencyInfo can be cleaned up farther:
>  * Hide the member variables.
>  * Introduce an internal AddLatencyNumberWithTimestampInternal, that takes in
> the bool parameter, and call into that from the public APIs with the
appropriate
> enum/bool value.
>  * Make this a class
> 
> This cleanup can happen in a follow-up CL. And if this is cleaned up soon,
then
> the bool param in this CL should be OK.

Yes. I am planning to remove the MergeWith() function soon and then the
|dump_to_trace| won't be needed.

[commit-bot: I haz the power, 2013-10-10 22:54:07]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/miletus@chromium.org/25022003/94001

[commit-bot: I haz the power, 2013-10-10 23:19:05]

Sorry for I got bad news for ya.
Compile failed with a clobber build on android_clang_dbg.
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=android_cl...
Your code is likely broken or HEAD is junk. Please ensure your
code is not broken then alert the build sheriffs.
Look at the try server FAQ for more details.

[commit-bot: I haz the power, 2013-10-10 23:46:49]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/miletus@chromium.org/25022003/121001

[commit-bot: I haz the power, 2013-10-10 23:56:17]

Step "update" is always a major failure.
Look at the try server FAQ for more details.
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=win&number...

[commit-bot: I haz the power, 2013-10-11 00:23:04]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/miletus@chromium.org/25022003/121001

[commit-bot: I haz the power, 2013-10-11 03:32:41]

Change committed as 228095