1405801 - Sleep(0) calls in WaitForGPUQuery() shows up in profiles

Status: NEW

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

Description

[(no longer active)]

A user is complaining about janky scrolling while watching the pixel 2 live stream (see bug 1400534 comment 15).  Looking at the profiles I noticed this Sleep(0) call is showing up a lot, for example, see https://perfht.ml/2yqKx5C and https://perfht.ml/2yoxv8O.

This may be nothing alarming but the profiles do show some long composite times, which cause the synchronous APZ messages from the UI thread to be blocked on the compositor, appearing as jank on the UI thread.

Comment 1

[(no longer active)]

Link to the code: <https://searchfox.org/mozilla-central/rev/e62604a97286f49993eb29c493672c17c7398da9/gfx/layers/d3d11/HelpersD3D11.h#26>

Comment 2

[Markus Stange [:mstange]]

Bas, is this the issue you've been looking into before?

Comment 3

[randomreporter]

Thank you very much for filing a bug!

(In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from comment #0)
> Sleep(0) call is showing up a lot, for example, see
> https://perfht.ml/2yqKx5C and https://perfht.ml/2yoxv8O.
To clarify: these are not my profiles, here are the profiles that I recorded:
https://perfht.ml/2xSsLI6
https://perfht.ml/2xSWn84

Comment 4

[Emanuel Hoogeveen [:ehoogeveen]]

To wit, Sleep(0) and Sleep(1) are special:
1) Sleep(0) yields the rest of the thread's slice if other threads are waiting, and waits for any pending I/O.
2) Sleep(1) yields for at least 1 slice.

The length of each slice depends on the thread granularity; we probably call timeBeginPeriod(1) which sets it to the minimum available interval, usually 0.5ms.

So Sleep(0) can either return immediately, wait for I/O or yield to another thread. There's also SwitchToThread() [1], which acts like Sleep(0) but doesn't wait for I/O (might be 'faster' than Sleep(0) on average due to that difference).

I haven't really looked at the code so I don't know if Sleep(0) is a necessary evil here, but I suppose we might be running into a situation where so many other threads are active that it takes a while before the OS returns to the compositor thread. 

One option that might be worth experimenting with is the Multimedia Class Scheduler Service (MMCSS) [2], which can be used to categorize threads as tasks with various characteristics.

[1] https://msdn.microsoft.com/en-us/library/windows/desktop/ms686352.aspx
[2] https://msdn.microsoft.com/en-us/library/windows/desktop/ms684247.aspx

Comment 5

[Bas Schouten (:bas.schouten)]

(In reply to :Ehsan Akhgari (needinfo please, extremely long backlog) from comment #0)
> A user is complaining about janky scrolling while watching the pixel 2 live
> stream (see bug 1400534 comment 15).  Looking at the profiles I noticed this
> Sleep(0) call is showing up a lot, for example, see
> https://perfht.ml/2yqKx5C and https://perfht.ml/2yoxv8O.
> 
> This may be nothing alarming but the profiles do show some long composite
> times, which cause the synchronous APZ messages from the UI thread to be
> blocked on the compositor, appearing as jank on the UI thread.

That sleep call showing up a lot means that the GPU is busy and we're spending a lot of time waiting for the -previous- composite to finish after submitting the current one. This can have one of two reasons:

1. The machine is busy/cannot composite a reasonable amount of things fast enough that we're asking it to composite.
2. We're trying to composite too much/something unreasonable

There's a bunch of profiles out there showing this, although in at least some cases it was the machine being swamped with other work, particularly work hogging memory bandwidth (in at least one case lots of videos being decoded was the cause).

(In reply to Emanuel Hoogeveen [:ehoogeveen] from comment #4)
> To wit, Sleep(0) and Sleep(1) are special:
> 1) Sleep(0) yields the rest of the thread's slice if other threads are
> waiting, and waits for any pending I/O.
> 2) Sleep(1) yields for at least 1 slice.
> 
> The length of each slice depends on the thread granularity; we probably call
> timeBeginPeriod(1) which sets it to the minimum available interval, usually
> 0.5ms.

This was true in pre-Win8 kernels, since then, NT kernels have been tickless aiui. Sleep(0) still behaves the same, it yields if stuff is waiting, otherwise returns right away (on a 20-core machine I tested with, it basically always returns within a couple of thousand cycles), so it essentially busy-loops -unless- there's other work waiting. Which will cause it to show up as doing a lot of work in profiles, and most certainly, it's eating up battery. Although it's not slowing the user's machine down.

Sleep(x) seems, on the post-win8 machines I tested on, to wait for x + (0.5 +/- 0.4 ms), this is just empirical data and not very useful.

In any case, when we hit this on the compositor, we've already posted a new -future- frame, and are waiting for the GPU to complete the -previous- one. It's certainly a bad sign, and there may be something that firefox can do better in its composition, but in itself it's a fairly meaningless signature.

Comment 6

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage/Projects/Bug_Handling/Bug_Husbandry#Move_fix-optionals