godotengine / godot

Godot Engine – Multi-platform 2D and 3D game engine
https://godotengine.org
MIT License
90.86k stars 21.14k forks source link

Print statements appear with a delay in the console, making it useless to debug input event timing issues #87493

Open davthedev opened 9 months ago

davthedev commented 9 months ago

Tested versions

System information

Godot v4.2.1.stable - Ubuntu 22.04.3 LTS 22.04 - X11 - Vulkan (Mobile) - integrated Intel(R) Iris(R) Plus Graphics (ICL GT2) () - Intel(R) Core(TM) i7-1065G7 CPU @ 1.30GHz (8 Threads)

Issue description

Print statements appear in the console with a slight delay when the project is run. I would rather have them appear in real time such as in Godot 3.5.1.

By "console" I mean the Output panel at the bottom of the main editor window, not the eventual OS-dependent terminal window.

This is very problematic when I debug issues related to input delays. In Godot 3.5.1, I can see the event appear in real time at the very moment the event happens in the window. This is not the case in Godot 4.2.1.

I am testing touchscreen events from a touch laptop. I would like to make sure Godot receives those in real time and this is not a problem with the OS instead that is likely to delay touches. For example, in browsers, there is a 300ms delay applied to disambiguate from scroll actions, and some desktop environments also preprocess those events to catch global gestures. Because of the delayed appearance of the output line in the console, I cannot sense at all if the event delivery delay is to blame on Godot or the operating system.

Steps to reproduce

Create a new project, make a 2d scene, add a script to the root node and add the following:

func _input(event):
    print(event)

Run the project. Do key strokes, mouse clicks, touch the screen if you have one, and notice that the corresponding output appears with a delay in the console.

Minimal reproduction project (MRP)

N/A

dalexeev commented 9 months ago

May be related:

Calinou commented 9 months ago

Can you reproduce this after enabling Interface > Editor > Update Continuously in the Editor Settings?

davthedev commented 9 months ago

It is much better, back to the realtime console output like in Godot 3!

Now, the "Update continuously" wording seems to have no relation to the console output. I would not have been able to discover it.

I guess, this can be related to the window redraw cycles capping that affects the console too, which is disabled when checking that box. If the window refresh rate is reduced to a lower value when unfocused, I can understand why there is so much perceptible delay in the logs. Is that correct?

Calinou commented 9 months ago

The reason this occurs is that editor redrawing in 4.x is limited to 10 FPS when the editor is unfocused by default. This also occurs in 3.x, but it's limited to 20 FPS instead, which means resource usage while unfocused is higher. You can change this by adjusting Unfocused Low Processor Mode Sleep Usec in the Editor Settings (lower values result in higher FPS).

I don't see a good way to resolve this without making the running project slower because the editor is fighting for resources in the background. This already occurs when something keeps the editor constantly redrawing in the background[^1] while the project is running, even at 10 FPS if your hardware is slow.

In the meantime, I suggest using a in-game console add-on so you can see prints directly in the running project with no delay. This also allows looking at prints while in fullscreen or on a mobile device.

[^1]: Particles, active AnimationPlayers in the editor, or shaders that use TIME.

davthedev commented 9 months ago

An idea would be a priority system for rendering parts of the editor.

Instead of enforcing a framerate cap on the entire thing, we can think about a way to pass down a rendering policy to the different nodes. Could be preset flags such as "normal / non-priority" or the specific framerate cap if it still makes sense. Depending on the value, each individual node would be responsible to limit its resource usage if applicable.

While most "dumb" widgets such as labels, tab containers, TreeViews do not consume that many cycles and update if there is actual interaction only, those who do constant rendering based on time or do heavy processing would slow down in consequence. For example, the animation player can skip frames; the particles node can do the same or just pause momentarily. The behaviour of each resource-intensive node can be adapted individually.

In addition, we can differentiate between the unfocused mode where the resources must be freed for the running game, and the unfocused situation where the user is just interacting with a different program on its operating system, maybe doing side-by-side Godot and another program on two monitors or split screen windows and doing some kind of visual comparison.

Calinou commented 9 months ago

An idea would be a priority system for rendering parts of the editor.

This is very complex to implement in practice, which is why the entire editor is always redrawn when something requests an update.

davthedev commented 9 months ago

That's right; there is no requirement of any partial redraw ability in my idea. It is only about letting each node know that there is a need to save resources. In turn, nodes that are the most performance-hungry would have their code adjusted so that they are aware of this information and request updates less often. The "light" nodes would nearly require no change to their behaviour.