VSync locking FPS at half under high load

[RustyMoyher]

VSync Lock Bug

When under a high workload on Mac or Windows, the FPS will clamp to a dramatically lower number (40, 30, 20, etc). This happens when running in fullscreen and VSync is enabled. If VSync is then disabled, the FPS will increase to a much higher number. (How high depends on the workload.)

Expected result: FPS might be slightly lower with VSync enabled, but not drop by 19 or 29 additional frames.

By default, VSync is enabled on mac and win32 builds. VSync can be enabled or disabled by calling glfwSwapInterval(1) and glfwSwapInterval(0) respectively.

Environment

Issue found on macOS and win32 builds. (Linux not tested)

• cocos2d-x versions:
  • 3.17.1
  • 3.13.1
• devices test on:
  • MacBook Pro 15-inch, Mid 2014 (MGXC2LL/A) - macOS 10.12.6
  • MacBook Pro 15-inch, Mid 2014 (MGXC2LL/A) - Windows 10
  • MacPro 2010 - macOS 10.12.6
  • HP Z420 - Windows 10
  • MacBook Pro 15-inch, Mid 2007 - macOS 10.10.5
• developing environments
  • Xcode version: 9.2
  • VS version: 2017 Professional

Videos + Test Code

Example Video - View at 1080p60 Example Video #2 - Shows how briefly disabling VSync can sometimes “unstick” the FPS. Test Code Gist Full Test Project Repo

Steps to Reproduce:

May be easiest to run my test project, but the bug should be reproducible without:

1. Create a fullscreen glView: GLViewImpl::createWithFullScreen
2. Display FPS counter: director->setDisplayStats(true);
3. Create enough work to tank the FPS. Often it will clamp at 30.
4. Disabled VSync with glfwSwapInterval(0) to observe the FPS change.

Additional Notes

I’ve experienced this bug under many conditions. For example, I was playtesting a game and used Alt+Tab to switch to the Windows desktop. When I returned to the game, the FPS was locked at 30. I’ve also noticed by reducing the workload temporarily, the FPS will sometimes return back to 60. If I briefly pause and then unpause my game while “VSync Locked”, sometimes the FPS will return to 60.

Video #2 shows a similar behavior. The work of adding 100 objects caused the FPS to fall to 30, but afterwards it remains stuck at 30. By simply turning VSync off and then on again, the FPS is restored to 60 FPS.

I’ve found two similar issues, but they seem Mac specific or lack details to reproduce. This bug is found across multiple platforms (Mac + Win32) and can be linked to VSync.

A Theory

It’s my understanding that VSync can block the main thread (by design) when void glfwSwapBuffers(GLFWwindow* window) is called. I suspect that this is causing a “feedback loop” with the Cocos2d-x run loop. That Cocos2d-x is waiting too long and skipping a frame, and then that causes the swapBuffer to skip a frame. However I’m unsure yet how to test this theory. (Sorry if this sounds silly. I’m still learning about the Cocos2d-x source.)

[minggo]

cocos2d-x uses its own main loop to render a scene, and the FPS is calculated based on it. So it is strange that the FPS is something about VSync. The only thing that related with VSync i can image is that, cocos2d-x invokes OpenGL API swapBuffer at the end of the frame, which will wait all OpenGL commands been executed. But i don't know the relationship between them, it is something about the implementation of OpenGL.

[RustyMoyher]

Hi minggo,

Thank you for taking a look at this! swapBuffers blocks all execution when VSync is on. Normally this isn’t problematic, but when under heavy load the VSync Lock Issue occurs.

I timed the duration of the swapBuffers block. The duration should be less than 1 frame (16666 microseconds). Normally I see something like this for each frame:

duration: 14489
duration: 14957
duration: 15044
duration: 14124
duration: 14559
(etc.)

But when the issue occurs, here is what I see for each frame:

duration: 33638
duration: 25043
duration: 25659
duration: 24241
duration: 26938
(etc.)

The confusing part is why even after the heavy load is finished, the FPS stays stuck at the lower rate. (Video #2 shows this behavior.)

Here’s the code I used to test the duration:

#include <chrono>
…
void GLViewImpl::swapBuffers()
{
    ::std::chrono::high_resolution_clock::time_point t1 = ::std::chrono::high_resolution_clock::now();

    if(_mainWindow)
        glfwSwapBuffers(_mainWindow);

    ::std::chrono::high_resolution_clock::time_point t2 = ::std::chrono::high_resolution_clock::now();
    auto duration = ::std::chrono::duration_cast<::std::chrono::microseconds>( t2 - t1 ).count();
    log("duration: %lld", duration);
}

[minggo]

Though it is not the same issue as this one, i found vsync issue in glfw issue system. So this one may be an issue of glfw too. Can update glfw to latest version to hav a try.

[Bilalmirza]

@minggo vsync issue started with mojave update. And this was fixed by apple last Thursday with the release of 10.14.4.

For win32 I believe you have adaptive sync on. This is a windows feature that locks on different fps depending on performance.

[minggo]

@Bilalmirza Thanks for the information of macOS.

For win32 I believe you have adaptive sync on. This is a windows feature that locks on different fps depending on performance.

Sorry, i don't quite understand it. Did you mean cocos2d-x does something wrongly?

[Bilalmirza]

@minggo i was talking about the vsync issue you mentioned earlier this has been fixed.

But @RustyMoyher might be talking about another issue not related to this.

@RustyMoyher will you be able to do some tests on the latest os?

[RustyMoyher]

@minggo @Bilalmirza I saw that issue on GLFW too, but it's Mac specific (and sounds like it's Mojave specific too?). What I'm experiencing is Mac and Windows. I can also reproduce the issue on a wide variety of OS versions.

But is seems like something worth testing anyways! I just pulled the latest code from the GLFW repo and build the almost-released GLFW 3.3. Unfortunately the VSync Lock Issue is still present.

[Bilalmirza]

macbook pro 2018, 10.14.4 https://www.youtube.com/watch?v=04fb3Cr3Dws

[TomerconDevelopers]

same issue