Godot: Single frame spikes even in an empty project

[ghost]

Godot version:
3.1.1, 3.2b2

OS/device including version:
Windows 10 Pro 1909 x64

Issue description:
Every ~10 seconds i get a one-frame spike followed by 1-3 really short frames. At first i thought it was my fault, but problem persists even in an empty project.

Exported project exhibits same behavior.

My specs are i5 7300, 16gb DDR4, GTX 1050

Profiler screenshots:

Frame before the spike:

Spike:

Frame after the spike:

Steps to reproduce:
1) Attach a script with empty "_process" method anywhere in the scene, so that Editor may pause the scene (only for a profiler screenshot)
2) Run project and wait for ~10 sec

EDIT:
So, in trying to narrow down the issue(at least as far as my abilities go), i tested this on some other machines

i7 - 9750H / 16 Gb DDR4 / RTX-2060 w/ Windows 10 - same thing,
i3 - 3240 / 4 Gb RAM (didn't check at the time, i believe DDR3) / GeForce 8600GT w/ Windows 8.1 - same thing

I tried to check the first machine (i5 7300, 16gb DDR4, GTX 1050) with Manjaro 18.1.5 and didn't notice any of similar problems (although i couldn't get Vsync to work). Project, exported on Manjaro to Windows exhibits same behavior

3.2 rc4 didn't help.

EDIT 2: The Editing
I decided to try Vulkan branch just to see if something different happens.
Spikes aren't there, but i noticed really strange things happen with everything that is normalized for time (with delta), i haven't noticed this before because of short lag, but in Vulkan that short lag isn't there, and after some investigating, i found that sometimes delta is negative(with same frequency as spikes in stable version). Going back to 3.2, negative delta does happen at the same time as spikes, but not everytime.

So i guess, question is, could VSync issues and negative delta be related?

[ghost]

So, pull request #33414 fixes it in windowed mode, but in fullscreen it still happens, and sometimes its only short frame and visible stutter (without the spike)

[FeralBytes]

@sigma0x How many FPS are you running? Is it possibly related to heat, or for that matter you are on Windows, are there other processes that are causing the bump? What happens if you implement the low processor mode in the project? Also some jitter at max FPS is definitely unavoidable as you computer could be doing any number of things. Even with Low Processor Mode jitter still maybe unavoidable, as the OS gets to determine scheduling, not Godot. Was this Jitter absent in previous versions?

[lawnjelly]

Also for things like this you really need to run it as an exported release and not from the IDE, to compare. When running in the IDE afaik it does all kinds of stuff which could lead to spikes (including communication with the IDE presumably, and there may even be some Sleeps in there when running in the IDE).

[Zylann]

One of the most obvious IDE things is the "remote scene tree", make sure it's not enabled when checking performance.

[ghost]

@sigma0x How many FPS are you running? Is it possibly related to heat, or for that matter you are on Windows, are there other processes that are causing the bump? What happens if you implement the low processor mode in the project? Also some jitter at max FPS is definitely unavoidable as you computer could be doing any number of things. Even with Low Processor Mode jitter still maybe unavoidable, as the OS gets to determine scheduling, not Godot. Was this Jitter absent in previous versions?

@FeralBytes FPS is stable 60 except for the issue itself. Heat is not a problem for sure (61 C at most on CPU package), but im not sure how to track down if any other processes cause this problem (no browser, or anything like that was active). Low processor mode seems to make issue appear less frequently, but more noticable. I didnt try versrions older than 3.1.1

[ghost]

Also for things like this you really need to run it as an exported release and not from the IDE, to compare. When running in the IDE afaik it does all kinds of stuff which could lead to spikes (including communication with the IDE presumably, and there may even be some Sleeps in there when running in the IDE).

@lawnjelly I double-checked everything in an exported project, profiler screenshots are just for demonstration. The issue behaves identically in editor and in exported release.

[ghost]

One of the most obvious IDE things is the "remote scene tree", make sure it's not enabled when checking performance.

@Zylann It wasnt enabled.

[qdwang]

Same issue here.

And my three computers have different results.

i5 2300 + 750Ti has the spike issue(the spike frametime is about 77ms).
i7 8550u + intel 620 doesn't have the spike issue.
amd r5 3600 + 1660super also has the spike issue(the spike frametime is about 44ms).

Maybe it's related with nvidia card only?

[Calinou]

To advance this issue's resolution, it might be worth trying to run Godot in an external profiler like Tracy to see what it's doing exactly when there are frame time spikes.

[nathanfranke]

So i guess, question is, could VSync issues and negative delta be related?

Probably related to https://github.com/godotengine/godot/issues/26887

a one-frame spike followed by 1-3 really short frames

See this comment by @zmanuel who knows a lot more about this stuff than I do:

The system here tries to keep the outgoing deltas stable within the given bounds by physics_jitter_fix, and that sometimes means the "game clock" (sum of outgoing deltas) is ahead of the real clock (sum of incoming deltas), this will happen if the framerate increased from one moment to the next. And then again sometimes, the system decides that being ahead was a mistake and that it should resync game and real clock while the current incoming delta is very small, smaller than the difference between the two times. The bug was that it would do so by letting the game clock snap back, creating a negative delta. Now it just stops for a bit.

---

Can someone check if this is reproducible in Master? If so, try locally merging https://github.com/godotengine/godot/pull/35617 and testing it again.

[lawnjelly]

One question is whether the profiler measured frame time is the same as the frame time processed by jitter fix which is fed to _process(delta).

A quick glance looks like it may not be, if the profiling is done on this line in main.cpp Main::iteration:

script_debugger->profiling_set_frame_times(USEC_TO_SEC(frame_time), USEC_TO_SEC(idle_process_ticks), USEC_TO_SEC(physics_process_ticks), frame_slice);

As nathanfranke says there is a fix in for zmanuel's jitter fix #35617 which may or may not cure the negative delta issue, although the 2 may not be directly related. You may even be getting the negative deltas as a result of the frame spike, rather than the other way around.

Personally I'm of the opinion we should have a pass through reference timing method available which doesn't use jitter fix code at all for this kind of thing (I included one in #30798). Perhaps we'll get to revisit timing code properly in 4.x it sorely needs an overhaul.

If the spikes are not jitter fix related, they could be related to something like garbage collection on the CPU (including driver) or GPU, or something OS related. Having a profile of the spike frame compared to the normal frames would be useful, maybe a GPU debugger might help with this to see if anything special was happening on these frames.

[qdwang]

I've tried to turn the Physics Jitter Fix to 0, the issue is still occurred.

[ghost]

Can someone check if this is reproducible in Master? If so, try locally merging #35617 and testing it again.

i cannot reproduce it in master at all right now. neither performance spikes, nor negative deltas

[ghost]

To advance this issue's resolution, it might be worth trying to run Godot in an _external_ profiler like Tracy to see what it's doing exactly when there are frame time spikes.

i am sorry if i sound stupid, but i can't understand how would i integrate something like tracy to profile the problem. i am eager to help, just don't get how to do that.

[Zylann]

Looking at https://github.com/godotengine/godot/issues/35996, you could try to measure how long this line takes to execute: https://github.com/godotengine/godot/blob/00949f0c5fcc6a4f8382a4a97d5591fd9ec380f8/platform/windows/context_gl_windows.cpp#L86
Just to verify. To do this you'd need to recompile the engine with some code added around it, to log something in case the call takes more than 32 ms?

[lawnjelly]

i cannot reproduce it in master at all right now. neither performance spikes, nor negative deltas

This would fit in with the hypothesis that it is caused by OpenGL (possibly garbage collection), rather than directly by Godot code (and negative deltas being a consequence rather than a cause).

[noidexe]

I'm using 3.2.2.rc2 and I'm getting a lag spike at almost exactly 30 seconds just like in #38815
I'm on windows 64 bits with a GTX 1050 and 60hz monitors.

It happens with GLES2, GLES3, vsync on/off, vsync via compostor on/off, windowed/fullscreen, setting jitter fix to 0, and even leaving the window unfocused and doing other tasks.
Then after around 200000 ms of runtime I start getting lagspikes more often.

I wrote this to keep track and see if the spikes where really happening at around the same time:

extends Label

# Called every frame. 'delta' is the elapsed time since the previous frame.
var last_frame_time = OS.get_system_time_msecs()
var config:ConfigFile
var run_id
var config_path = "user://lagspikes.ini"

func _ready():
    randomize()
    run_id = str(randi()) + str(randi())
    config = ConfigFile.new()
    var err = config.load(config_path)
    if err == ERR_FILE_NOT_FOUND:
        config.save(config_path)



func _process(delta):
    if delta > 0.08:
        var spike = [str(OS.get_ticks_msec()), str(delta)]
        text += "Time: %s, dt: %s\n" % spike
        config.set_value(run_id, spike[0], spike[1])
    pass

func _notification(what):
    if what == NOTIFICATION_WM_QUIT_REQUEST:
        config.set_value(run_id, "total_run_time", str(round(OS.get_ticks_msec())))
        config.set_value(run_id, "vsync", ProjectSettings.get_setting("display/window/vsync/use_vsync"))
        config.set_value(run_id, "vsync_comp", ProjectSettings.get_setting("display/window/vsync/vsync_via_compositor"))
        config.set_value(run_id, "windowed", !OS.window_fullscreen)
        config.set_value(run_id, "driver", ProjectSettings.get_setting("rendering/quality/driver/driver_name"))
        config.set_value(run_id, "batching", ProjectSettings.get_setting("rendering/batching/options/use_batching"))
        config.save(config_path)

I also tracked it by hand with a cronometer just in case and the script doesn't seem to have any effect in whether the spikes happen or not, or their timestamps.

[clayrone]

I am also experiencing this issue both in editor and exported version.
It is clearly visible stutter when moving the player, but it also happens on idle run, always around 30 seconds in.

Godot Version
3.2.2 stable

Spec
Ryzen 3800X, GeForce RTX 2070 SUPER, Windows 10 PRO

---

[qdwang]

Can this issue be fixed in the future 3.2.x version? Or we have to wait until the 4.0 release?

[Calinou]

@qdwang We don't know when this will be fixed, as no definite cause has been identified yet. That said, a fix can likely be cherry-picked to the 3.2 branch once it's merged in master.