1324649 - Background color change does not follow the cursor quickly enough on GMail

Status: RESOLVED WORKSFORME

(Core :: JavaScript Engine, defect)

Description

[Tim Guan-tin Chien [:timdream] (please needinfo)]

STR:

1. Go to GMail and pick a theme. You would also need a more few labels on the menu of the right hand side.
2. Quickly move the cursor across the menu. There will be a solid color background on the hovered item.
3. Observe the change of the background and also the position of the cursor.

Expected result:

1. No noticeable delay between two. Background color change should always follow the cursor.

Actual:

1. A more than 100ms delay can often observed. The background color "bar" continue to move sometimes long after the cursor has stopped moving.

Note:

1. Can't be quite noticeable when the background tabs are busy, but either e10s nor multi-e10s fix this to a point the user will be happy with.
2. I don't have time to dive into profiling nor reduced test, but I suspect this is not just because of the layout and the complex mark-up as they might have JS event listener on these mouseover/mouseout etc too.

I hope this is actionable ...

Comment 1

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Same thing happens on Facebook sidebar too, should be a different bug if the cause is very different.

Comment 2

[Ciprian Muresan [:cmuresan], Ecosystem QA]

User Agent 	Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:53.0) Gecko/20100101 Firefox/53.0

Hi Tim,

Could you please attach a screen recording of the issue you are experiencing? Because I don't really understand where this menu on the right hand side is.

Comment 3

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Damn. I mean the LEFT hand side .... sorry about that.

Ni me again if you still need an video.

Comment 4

[Ciprian Muresan [:cmuresan], Ecosystem QA]

The only delay I can see while hovering the left side menu is only at page load. After the page is fully loaded, the hover effects don't seem to have a delay. 

Could you take a look at the screen recording (https://goo.gl/EmTt0B) I made and tell me if it's the same thing you are experiencing?

Comment 5

[Tim Guan-tin Chien [:timdream] (please needinfo)]

I am having trouble playing that recording. There was a 403 Forbidden in the DevTools log.

What you described in written is similar to what I experienced, assuming by "at page load" you also include when there is a background page loading.

Comment 6

[Ciprian Muresan [:cmuresan], Ecosystem QA]

Tim, do you know which team should be working on this issue?

Comment 7

[Tim Guan-tin Chien [:timdream] (please needinfo)]

I don't know, really. We would need a profile result to figure that out.

Comment 8

[Ciprian Muresan [:cmuresan], Ecosystem QA]

Finally got around to getting a profile: https://clptr.io/2kJkejK

Tim, can you take a look at the profile or get someone to look over it?

Comment 9

[Tim Guan-tin Chien [:timdream] (please needinfo)]

Thanks. I can see the profile shows many red bars labeled with "Xms event processing delay on the tab thread".

On many of these red bars, the tab thread is blocked on a GMail script handling xhr.onreadystatechange. One of these blocked by script loader. I wonder what we could do to in Gecko -- tentatively throw this to JS engine.

Comment 10

[(no longer active)]

I looked at this profile today.  Here are my findings.

The biggest pause is https://clptr.io/2ktJv0R.  This starts off by about 90ms of top level execution of a hangouts script[1].  That’s a long time, not sure what’s special about this script and why it’s so slow.  Then there is 230ms of executing something from [1].  The stack above this wasn’t walked properly, but I’ve often seen this happen in setTimeout() callbacks and such.  After that again something similar perhaps from another timeout for 145ms.  Then there is 87ms of cycle collection immediately, followed by a 2ms PBrowser::Msg_RealMouseMoveEvent followed by a Gmail paint as a result of processing PVsync::Msg_Notify.

I looked at a few of the other pauses as well.  There was one more of the one above <https://clptr.io/2ku3kVF> (from the same script.)  Another one <https://clptr.io/2ktKGx6> was 155ms of running line 146 of [2].  Another one <https://clptr.io/2ktKxtK> was 425ms of running [2].

I didn’t look further but in short, running scripts on Gmail is slow.  I’m planning to look a bit more into why that is tomorrow.

But more importantly, the case in the first paragraph seems to be several runnable that are processed before processing vsync.  Olli, why are we not processing vsync with a higher frequency?  For example, if you do a bunch of setTimeout(0)’s, is it possible for them all to run before vsync being processed?

[1] https://hangouts.google.com/_/scs/chat-static/_/js/k=chat.wbl.en.ve8G_VWpVDY.O/m=b,bst,c,ca,cnv,md,r/am=APoRAiAAhYiaJBQD/rt=j/d=1/rs=AGNGyv3VSGK9Fbpbjg6E5J3JEncK5WkmkQ
[2] https://mail.google.com/_/scs/mail-static/_/js/k=gmail.main.en.fp3nX7VQFPI.O/m=m_i,pdt,t,it/am=ZnEOQv7f94c4ZABQNjVRw-w985tP5YM53_P_zz9AosNPwP_N_h_g_wAAAAAAAAAAAAAAAAAAAAAAW9Sg/rt=h/d=1/rs=AHGWq9DtiLJfnQYTtUdNXjwGFLKPMWo7vg

Comment 11

[Olli Pettay [:smaug][[e-mail]]]

high priority vsync is disabled. Re-enabling is waiting for review.

Comment 12

[(no longer active)]

(In reply to Olli Pettay [:smaug] from comment #11)
> high priority vsync is disabled. Re-enabling is waiting for review.

Is there a bug to re-enable it?  I think we should reprofile this when that happens.

Comment 13

[Olli Pettay [:smaug][[e-mail]]]

Bug 1332226. I'll land that during the weekend.

Comment 14

[Andrew Overholt [:overholt]]

Tim/Ciprian: can you re-profile given that the prioritized vsync has landed and stuck?

Comment 15

[Andrew Overholt [:overholt]]

(Ugh, sorry about needinfoing the wrong person /o\)

Comment 16

[Ciprian Muresan [:cmuresan], Ecosystem QA]

The behavior doesn't seem at all improved: https://perfht.ml/2pTU1lZ.

Comment 17

[Andrew Overholt [:overholt]]

Thank you for re-profiling. I'm nominating for Quantum Flow to see if it should be tracked there.

Comment 18

[Olli Pettay [:smaug][[e-mail]]]

FWIW, I see lots of promise usage. There is for example one 139ms pause under PromiseJobCallback::Call.
Promises are synchronous from UA point of view, but JS often uses them as if they were async.
Anyhow, that is all Hangouts JS.
And before that there is 656ms other Hangouts script.

The page seems to also cause quite a bit garbage, since stuff under SnowWhiteKiller take some time, assuming the profile is just from that one page.

Comment 19

[(no longer active)]

(In reply to Olli Pettay [:smaug] from comment #18)
> The page seems to also cause quite a bit garbage, since stuff under
> SnowWhiteKiller take some time, assuming the profile is just from that one
> page.

This may have been improved in bug 1367164.  May be worth reprofiling.

Comment 20

[Andrew Overholt [:overholt]]

I wanted to re-profile this but can't reproduce, even with data:text/html,<script>while(true);</script> in a background tab.

Tim, can you still reproduce?

Comment 21

[Tim Guan-tin Chien [:timdream] (please needinfo)]

I have not been able to reproduce this for quite some time. Thanks everyone! WFM?

Comment 22

[Andrew Overholt [:overholt]]

WFM :)

Comment 23

[(no longer active)]

Thanks Tim, please reopen if you saw this (or any other performance issue in Gmail) again!