New issue
Advanced search Search tips

Issue 923498 link

Starred by 2 users

Issue metadata

Status: Assigned
Owner:
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Windows
Pri: 3
Type: Bug



Sign in to add a comment

Event.Latency.ScrollUpdate.Wheel.TimeToScrollUpdateSwapBegin4 not always logged for wheel scrolling

Project Member Reported by dli...@microsoft.com, Jan 18 (4 days ago)

Issue description

Chrome Version: 73.0.3676.0 (Official Build) canary (64-bit) (cohort: Clang-64)
OS: Win10

What steps will reproduce the problem?
(1) Open a fresh instance of Chrome
(2) Go to a site with composited scrolling (e.g. en.wikipedia.org/
(3) Scroll with a mouse wheel
(4) go to chrome://histograms

What is the expected result?
See some data points for Event.Latency.ScrollUpdate.Wheel.TimeToScrollUpdateSwapBegin4


What happens instead?
Only see data for Event.Latency.ScrollBegin.Wheel.TimeToScrollUpdateSwapBegin4

I've attached a trace that shows only the first InputLatency::GestureScrollUpdate has a INPUT_EVENT_GPU_SWAP_BUFFER_COMPONENT - the rest are completed with INPUT_EVENT_LATENCY_ACK_RWH_COMPONENT


 
trace_wheel-gsu-no-swaps.json.gz
479 KB Download

Comment 1 by dli...@microsoft.com, Jan 18 (4 days ago)

Here’s what I’ve debugged on Windows desktop – in the ‘happy path’ (i.e. one in which we get a Event.Latency.ScrollBegin.Wheel.TimeToScrollUpdateSwapBegin4) we see this sequence:
1.	The first GSU is handled synchronously instead of getting queued in the compositor_event_queue_. 
2.	Handling the first GSU creates the scroll-offset animation (LayerTreeHostImpl::ScrollAnimationCreate)
3.	ScrollAnimationCreate calls LayerTreeHostImpl::SetNeedsOneBeginImplFrame
4.	Because this happens within the scope of InputHandlerProxy::DispatchSingleInputEvent, there’s a SwapPromiseMonitor on the LayerTreeHostImpl, which is notified of the need for redraw
5.	This will call LayerTreeImpl::QueuePinnedSwapPromise, which adds the swap promise to a list that is ‘finished’ when a compositor frame is generated
6.	LatencyInfoSwapPromise::WillSwap will add a LatencyInfo to the compositor frame metadata, which is shipped off to the display compositor, where eventually the Swap will happen and the LatencyInfo will be completed 

For subsequent GSUs generated by mouse wheel we instead see the following:
1.	Subsequent GSU is queued, and this code detects that we need to animate for the input (SetNeedsAnimateInput calls SetNeedsOneBeginImplFrame)
bool needs_animate_input = compositor_event_queue_->empty();
    compositor_event_queue_->Queue(std::move(event_with_callback),
                                   tick_clock_->NowTicks());
    if (needs_animate_input)
      input_handler_->SetNeedsAnimateInput();
    return;
2.	There is no SwapPromiseMonitor registered on LayerTreeHostImpl (not called within scope of InputHandlerProxy::DispatchSingleInputEvent)
3.	Later when the GSU is handled on BeginFrame for impl thread, the animation target is updated (LayerTreeHostImpl::ScrollAnimationUpdateTarget), but nothing calls to LayerTreeHostImpl::SetNeedsOneBeginImplFrame or SetNeedsRedraw

For this second sequence, the latency info’s associated with the GSU’s are not shipped off with the compositor frame, so we don’t get the data point. 


Note I see similar issues with main thread driven scroll animations, but I suspect the root cause is different. I'm not as familiar with those, so needs more investigation on my end

Comment 2 by sadrul@chromium.org, Yesterday (39 hours ago)

Cc: sadrul@chromium.org

Comment 3 by nzolghadr@google.com, Yesterday (34 hours ago)

Cc: sahel@chromium.org
Status: Assigned (was: Untriaged)

Comment 4 by nzolghadr@google.com, Yesterday (34 hours ago)

Components: -Internals>Input Blink>Scroll

Sign in to add a comment