1649708 - Horrible input latency in many scenarios

Status: RESOLVED FIXED

(Core :: Graphics: WebRender, defect, P3)

Description

[Katelyn Gadd (:kael)]

Attachment: Firefox 2020-07-01 02.44 profile.json.gz

Input latency is really bad lately in FF on my desktop. The actual performance of the browser seems fine, but things like mouseover hover styles take hundreds of milliseconds to update, even for browser chrome (though pages are worse, obviously). I haven't been able to identify any specific tabs responsible for this, though it seems like the lag on things like Tree Style Tab are worse when viewing a heavy tab. This still happens with Tree Style Tab closed, fwiw - TST is just the easiest way to notice since the highlight on mouseover lags really bad for no obvious reason.

The most obvious thing to me is that mouseover processing spends a massive amount of time blocked waiting for some sort of signal, which would explain why I see such a delay responding to mouse movement. Text input latency doesn't seem as bad, right now typing into the bugzilla textarea feels okay but TST on the side is still somewhat laggy. Typing into twitter's textarea is maybe slightly laggy but still not as bad as mouse input. Scrolling feels vaguely responsive but is definitely not 60hz under this scenario, at least not consistently.

Attaching a profile since the permalink thing in the online profiler doesn't seem to work anymore.

Comment 1

[Katelyn Gadd (:kael)]

Attachment: Screen recording

Here's a desktop recording of me mousing around on tree style tab. It may be my imagination but the lag is slightly better when viewing the new tab page - not really to the point it should be though, still feels bad.

Comment 2

[Katelyn Gadd (:kael)]

From further testing, this seems to temporarily improve if I restart the entire browser. Closing tabs (even the heavy-weight ones) doesn't seem to do anything though.

Comment 3

[Mike Conley (:mconley) (:⚙️)]

Here's the profile (with the hidden threads removed to reduce the size - publishing was failing because the profile was too large): https://share.firefox.dev/38ATSqQ

It looks to me like the main thread in the parent process is blocked waiting on APZ to send sync IPC messages for the mouse input events. Those sync messages are presumably going to the compositor process, and it looks like they're associated with pretty long pauses on the compositor thread waiting for Webrender to ... webrender. Hey jrmuizel, anything actionable in there, graphics-wise?

Comment 4

[Jeff Muizelaar [:jrmuizel]]

Katelyn, what's the memory usage in the GPU process when you see this?

Comment 5

[Katelyn Gadd (:kael)]

I haven't reproduced a degraded situation like this report since the last time I restarted FF, but I've had it open for a bit now, here's the relevant memory stats for the GPU process

308.76 MB (100.0%) -- explicit
├──233.30 MB (75.56%) ── heap-unclassified
├───42.98 MB (13.92%) -- gfx
│ ├──36.15 MB (11.71%) -- webrender
│ │ ├──17.29 MB (05.60%) ── display-list
│ │ ├───9.18 MB (02.97%) -- resource-cache
│ │ │ ├──9.18 MB (02.97%) ── fonts
│ │ │ └──0.00 MB (00.00%) ++ (2 tiny)
│ │ ├───7.56 MB (02.45%) -- interning
│ │ │ ├──4.37 MB (01.41%) ++ (13 tiny)
│ │ │ └──3.20 MB (01.03%) ++ text_run
│ │ └───2.12 MB (00.69%) ++ (5 tiny)
│ └───6.83 MB (02.21%) ── native-font-resource-data
├───27.37 MB (08.86%) -- heap-overhead
│ ├──19.19 MB (06.22%) ── bin-unused
│ ├───5.25 MB (01.70%) ── bookkeeping
│ └───2.92 MB (00.95%) ++ (2 tiny)
├────4.75 MB (01.54%) -- threads
│ ├──3.44 MB (01.11%) ++ stacks
│ └──1.32 MB (00.43%) ++ overhead
└────0.36 MB (00.12%) ++ (6 tiny)

Other Measurements

134,217,727.94 MB (100.0%) -- address-space
├──132,111,396.74 MB (98.43%) ── free(segments=1320)
├────2,102,669.71 MB (01.57%) -- reserved
│ ├──2,097,135.25 MB (01.56%) ── mapped(segments=13)
│ └──────5,534.47 MB (00.00%) ── private(segments=2257)
└────────3,661.48 MB (00.00%) ++ commit

1,627.50 MB (100.0%) -- gfx
└──1,627.50 MB (100.0%) -- webrender
├──1,439.15 MB (88.43%) -- textures
│ ├──1,021.93 MB (62.79%) ── texture-cache
│ ├────189.63 MB (11.65%) ── render-targets
│ ├────152.97 MB (09.40%) ── swap-chains
│ ├─────69.00 MB (04.24%) ── depth-targets
│ └──────5.63 MB (00.35%) ++ (2 tiny)
└────188.36 MB (11.57%) -- images/mapped_from_owner
├──109.32 MB (06.72%) -- pid=29044
│ ├───58.70 MB (03.61%) ── image(905x1308, compositor_ref:1, creator_ref:0)/decoded-nonheap [13]
│ └───50.62 MB (03.11%) ++ (21 tiny)
├───29.58 MB (01.82%) ++ (8 tiny)
├───27.46 MB (01.69%) ++ pid=14824
└───21.99 MB (01.35%) ++ pid=12504

Comment 6

[Markus Stange [:mstange]]

Once this happens again, can you get another profile with the following threads added to the threads filter? ",Renderer,RenderBackend"

Comment 7

[Katelyn Gadd (:kael)]

Here's another profile that I think is the same problem, with RenderBackend enabled.
https://share.firefox.dev/2CGhdeV

Comment 8

[Jeff Muizelaar [:jrmuizel]]

(In reply to Katelyn Gadd (:kael) from comment #7)

Here's another profile that I think is the same problem, with RenderBackend enabled.
https://share.firefox.dev/2CGhdeV

And what does about:memory/task manager say for the GPU process memory usage?

Comment 9

[Katelyn Gadd (:kael)]

Just closed it to do a test on a fresh start (https://share.firefox.dev/2CqvigF) with the same steps - mousewheel scroll and mouse over links a lot on Twitter - to verify that it wasn't as bad on a fresh session (it's not). Glancing at the profile it seems like it spends much less time holding the mutex inside APZC functions but nothing obvious there.

The last time I checked the GPU process's memory usage (a few hours ago I think?) It was in the 1GB range. This fresh session's GPU usage:

893.19 MB (100.0%) -- gfx
└──893.19 MB (100.0%) -- webrender
├──802.74 MB (89.87%) -- textures
│ ├──522.58 MB (58.51%) ── texture-cache
│ ├──147.41 MB (16.50%) ── swap-chains
│ ├──111.00 MB (12.43%) ── render-targets
│ ├───19.19 MB (02.15%) ── depth-targets
│ └────2.56 MB (00.29%) ++ (2 tiny)
└───90.45 MB (10.13%) -- images/mapped_from_owner
├──31.25 MB (03.50%) ++ pid=21388
├──22.69 MB (02.54%) -- pid=21612
│ ├──15.63 MB (01.75%) ── image(2560x1600, compositor_ref:2, creator_ref:1)/decoded-nonheap
│ └───7.07 MB (00.79%) ++ (21 tiny)
├──20.82 MB (02.33%) ++ pid=3856
├──10.01 MB (01.12%) ++ pid=2892
└───5.69 MB (00.64%) ++ (6 tiny)

I have a memory report I took last night for another issue where the GPU process reports this:

1,347.30 MB (100.0%) -- gfx
└──1,347.30 MB (100.0%) -- webrender
├──1,209.53 MB (89.77%) -- textures
│ ├────975.44 MB (72.40%) ── texture-cache
│ ├─────96.81 MB (07.19%) ── render-targets
│ ├─────91.47 MB (06.79%) ── swap-chains
│ ├─────39.72 MB (02.95%) ── depth-targets
│ └──────6.08 MB (00.45%) ++ (2 tiny)
└────137.77 MB (10.23%) -- images/mapped_from_owner
├───51.43 MB (03.82%) ++ pid=14468
├───32.46 MB (02.41%) ++ (7 tiny)
├───23.60 MB (01.75%) -- pid=12340
│ ├──15.63 MB (01.16%) ── image(2560x1600, compositor_ref:1, creator_ref:0)/decoded-nonheap
│ └───7.97 MB (00.59%) ++ (26 tiny)
├───15.27 MB (01.13%) ++ pid=14528
└───15.02 MB (01.11%) ++ pid=14600

Comment 10

[Jeff Muizelaar [:jrmuizel]]

There's something really weird going on with the RenderBackend in this profile: https://share.firefox.dev/2CGhdeV. In the more recent profile it looks like you've just got really long running javascript. Like a refresh driver tick takes 188ms. Without having URLs in the profile it's hard to know what script that is. Do you have any addons that might be doing bad things?

Comment 11

[Katelyn Gadd (:kael)]

Tree Style Tab and uBlock. I had issues like this before I started using TST, but TST might make them worse. Is there a way to monitor addons' CPU usage/javascript utilization? All I see is "energy impact" in about:performance.

The page I'm testing on is Twitter so its javascript is pretty heavy - I use it because it's much easier to see whether the lag is present given how the page is built (longer delay before content shows up when scrolling, longer delay on button mouseover, etc). It's hard for me to tell whether it's reproducing on a light page like Bugzilla since it seems like stuff is fast enough on light pages for it to not cause frames to drop.

Comment 12

[Mike Conley (:mconley) (:⚙️)]

The parent process also seems to be animating something. Was something animating in the toolbars? For example, was the download button showing a progress bar because a download was in-flight?

Comment 13

[Katelyn Gadd (:kael)]

Good catch, I think I had a download in progress. I'll keep an eye out for that next time, maybe it's part of the repro steps.

Comment 14

[Wayne Mery (:wsmwk)]

(In reply to Katelyn Gadd (:kael) from comment #13)

Good catch, I think I had a download in progress. I'll keep an eye out for that next time, maybe it's part of the repro steps.

Are you stil seeing this?

Comment 15

[Katelyn Gadd (:kael)]

I haven't seen it recently, my workflow has changed a bit since I reported it (I no longer use regular web Twitter) but it seems likely that it was fixed.