Godot: Getting negative `delta` values for `_process`

[trommlbomml]

Godot version:
Godot 3.1. RC 1

OS/device including version:
Windows 10 Home 64-bit, Geforce GTX 860m

Issue description:
I already found some similar issue, but it was related to android only. Therefore I named the issue similar but the error also seems to occur on windows machines.

I noticed my script crashes because of a division by zero (Stripped down to relevant part):

func _process(delta):
    if abs(angle) > PI * 4 * delta:
        thisRotation = current.slerp(target, max_radians_delta / abs(angle))
    else:
        thisRotation = current.slerp(target, 1)

For my case, angle = 0. If delta is negative the first code path is executed and results in a division by zero error. This happens sometimes when I start my game and do not move my character.

If this is relevant: I use the bullet physics with KinematicBody and StaticBodyies.

Minimal reproduction project:
I would provide the project if not easy to reproduce, I think a simple print if delta < 0 is sufficient.

[matthew1006]

I also have this problem with 3.1 stable on Windows 7.

[nathanfranke]

Reproducable on Ubuntu 18.04.2 LTS (Kernal x86_64 Linux 4.18.0-17-generic)
GeForce GTX 960

Godot: v3.1.stable.mono.official

The issue only seems to come during very high stress (In my example, a ton of high poly spheres are spawned)

GodotTestProject.zip

[Faless]

To anyone that can reproduce the original issue
can you try this branch?
https://github.com/Faless/godot/tree/spike/clock_info
Is it still happening there?

The patch just tries to avoid some unnecessary math, limiting potential overflows and hopefully minimizing numerical errors:
https://github.com/godotengine/godot/compare/master...Faless:spike/clock_info

(there is also a 3.1 version of this patch: https://github.com/Faless/godot/tree/spike/clock_info_3.1 )

[nathanfranke]

I can still reproduce this in all branches. More data below

Ubuntu 18.04.2 LTS
Kernal x86_64 Linux 4.18.0-17-generic
GeForce GTX 960

@Faless branch Standard: Bug is Reproducible
Master Standard, Master Mono: Bug is Reproducible

Seems to happen somewhat randomly, and behavior can be changed based on background processes and performance

Updated test project:
_This project uses GDScript rather than C# so that the bug is testable in the Standard version._
GodotTestProject.zip

[Faless]

Can you also provide CPU and motherboard details?

On Thu, Oct 17, 2019, 01:04 Nathan Franke [e-mail] wrote:

Ubuntu 18.04.2 LTS
Kernal x86_64 Linux 4.18.0-17-generic
GeForce GTX 960

@Faless https://github.com/Faless branch
https://github.com/Faless/godot/tree/spike/clock_info Standard: Bug is
Reproducible
Master Standard, Master Mono: Bug is Reproducible

Updated test project:
This project uses GDScript rather than C# so that the bug is testable in
the Standard version.
GodotTestProject.zip
https://github.com/godotengine/godot/files/3736690/GodotTestProject.zip

If anyone else is able/unable to reproduce this, please reply

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/godotengine/godot/issues/26887?email_source=notifications&email_token=AAM4C3WABZN6BSCIN5TZFN3QO6MWPA5CNFSM4G46HJO2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEBOGLOI#issuecomment-542926265,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AAM4C3TVHDGNB2ACEDNCCPDQO6MWPANCNFSM4G46HJOQ
.

[Faless]

Also, does this also happen when vsync is enabled? (I see it's disabled in
project settings). How many fps are you getting without vsync?

On Fri, Oct 18, 2019, 13:50 Fabio Alessandrelli <
[email protected]> wrote:

Can you also provide CPU and motherboard details?

On Thu, Oct 17, 2019, 01:04 Nathan Franke [e-mail]
wrote:

Ubuntu 18.04.2 LTS
Kernal x86_64 Linux 4.18.0-17-generic
GeForce GTX 960

@Faless https://github.com/Faless branch
https://github.com/Faless/godot/tree/spike/clock_info Standard: Bug
is Reproducible
Master Standard, Master Mono: Bug is Reproducible

Updated test project:
This project uses GDScript rather than C# so that the bug is testable in
the Standard version.
GodotTestProject.zip
https://github.com/godotengine/godot/files/3736690/GodotTestProject.zip

If anyone else is able/unable to reproduce this, please reply

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/godotengine/godot/issues/26887?email_source=notifications&email_token=AAM4C3WABZN6BSCIN5TZFN3QO6MWPA5CNFSM4G46HJO2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEBOGLOI#issuecomment-542926265,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AAM4C3TVHDGNB2ACEDNCCPDQO6MWPANCNFSM4G46HJOQ
.

[nathanfranke]

Motherboard: Gigabyte H170-Gaming 3
CPU: Intel i5 6600k

Not at home to check Vsync enabled, but I always get 60fps using it
Without Vsync I get hundreds of FPS, however the bug seems to only appear during lag spikes or bad performance

[Faless]

Yeah, sorry.
I meant how many fps you get _without_ vsync.

And separately, if the negative delta problem is present _with_ vsync.

Sorry for not being clear :-)

On Fri, Oct 18, 2019, 15:54 Nathan Franke [e-mail] wrote:

Motherboard: Gigabyte H170-Gaming 3
CPU: Intel i5 6600k

Not at home to check Vsync enabled, but I always get 60fps using it

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/godotengine/godot/issues/26887?email_source=notifications&email_token=AAM4C3R644ODLOQOUD5PZ63QPG5X5A5CNFSM4G46HJO2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEBURK7Y#issuecomment-543757695,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AAM4C3TSSXQQEFH76VVU47DQPG5X5ANCNFSM4G46HJOQ
.

[nathanfranke]

No problem edited my response already

[Faless]

Sorry to insist, but does the bug happen when vsync is enabled? That is
quite crucial to know. Thanks!

On Fri, Oct 18, 2019, 17:15 Nathan Franke [e-mail] wrote:

No problem edited my response already

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/godotengine/godot/issues/26887?email_source=notifications&email_token=AAM4C3VOXIPGRLZW7UCZS6DQPHHKTA5CNFSM4G46HJO2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEBUZWZQ#issuecomment-543791974,
or unsubscribe
https://github.com/notifications/unsubscribe-auth/AAM4C3RI7UXRORZRYCL4K5TQPHHKTANCNFSM4G46HJOQ
.

[nathanfranke]

I cannot reproduce this bug with VSync enabled

[Faless]

I cannot reproduce this bug with VSync enabled

I see, and am I guessing right that when you get negative deltas it's actually an incredibly small negative value? (i.e. negative zero -0.00000)

[nathanfranke]

Correct. The values are quite small. Here is a log

0.005
0.07277458
0.01940706
0.032334
0.01548033
-0.0005547218

Therefore it is likely unrelated to the Android bug that was fixed (mentioned above)

[nathanfranke]

I found a very easy way to reproduce this. I am assuming it only happens on Unix since the problem is likely in OS_Unix::get_ticks_usec which calls SceneTree::idle with a negative p_time

Here is the script that has <0 delta consistently after 1-2 seconds

extends Node

func _process(delta : float):
    if delta < 0:
        print(delta)

    if randf() < 0.25: # Inconsistent lag spikes
        stress()

func stress():
    for i in range(100000):
        randi()

TimeBug.zip

[lawnjelly]

@nathanwfranke Well done on finding a reproducible project, I've had a look at similar problem in the past. A quick look and it does report negative deltas on mine too...

and it looks like it is down to the 'jitter fix' code #17353. If I set jitter fix to 0.0 (from 0.5) I no longer get negative deltas. @zmanuel

[zmanuel]

Thanks for the notice. I only have the vaguest idea of how this could be possible, I'll look into it.

[zmanuel]

The crucial error is the line
'p_idle_step += time_deficit;`
p_idle_step is the timestep as measured by the clock at that point, the value afterward is used. Since the game clock is allowed to deviate from the real clock both ways, time_deficit may be negative and pul p_idle_step into the negative if the initial value is small.
I have it fixed locally, but want to do some more testing and thinking before I push it out, there may be other issues and I don't want to break any other promises expected of sensible timestep arguments.

[nathanfranke]

@zmanuel I think you should open a new pull request with the valid changes. I can close this once you do that (and we'll need someone to add all the labels and milestone)

[zmanuel]

'course :) Done so now. The last post was just a before-bed status report.

I decided against just fixing the mentioned line; there are at least one possible other way a negative delta can come about later. One I actually managed to provoke is if you change physics_jitter_fix at runtime, which you are allowed to do:
Engine.physics_jitter_fix = randf()*3
then the shifting limits may also pull the timer backwards. That needs correcting near the end, so I just do that.

Another effect is that the number of physics steps to simulate can become negative. That is simply caught and corrected.

And lastly, after the delta has been corrected to be positive, it may turn out you need to do another physics step to keep physics_interpolation_fraction between 0 and 1. One could just clamp it, but then you violate the relation
Sum of delta arguments to _process = Sum of delta arguments to _physics_process + physics_interpolation_fraction/physics_fps
that should hold when you call _process.

Great test case, @nathanwfranke.

[Zylann]

Just got a zero delta in _process with Godot 3.2.2 beta3, while testing my game. It caused a division by zero.
I'd be incapable of providing any repro though, it just "happened" randomly after playing 16 levels.

[nathanfranke]

I can reproduce this in 3.2.2 beta 3, but interestingly the only value printed is approximately -0.000000001863, rounded down to -0 when printed.

print(delta * 1000000.0)

-0.001863
-0.001863
-0.001863
-0.001863
-0.001863

[zmanuel]

Just got a zero delta in _process with Godot 3.2.2 beta3, while testing my game. It caused a division by zero.

Note there, see discussion on #35617: That PR in its current form will not prevent zero as _process argument, just negative values. My cruel position is that if you get a division by zero on a vanishing timestep, you're doing something wrong and should rework the math; simple example, when tweening values, it is tempting to write a factor 1/(1+1/delta)), that should be rewritten as delta/(delta+1). It should always be possible to express your timestep in a way that makes it self-evident that _process(delta -> 0) simply does nothing.
I get that that's in conflict with ease of use :) The version of the PR that clamps at some positive delta argument is also still around, just in case.

[Zylann]

@zmanuel well in my case I didnt really have much of a choice, it's in calculation of a derivative. delta=0 here would mean no time elapsed, so... I just returned at the beginning of the function, which then might as well not have been called. And if I had code that luckily did nothing, then still no point running it. And if delta is negative, I believe it should also not run either, because where would a "positive" value come from then? Such cases make no sense, unless you are inclined to implement your game simulation for every possible value of delta, be it negative or zero, that's quite a big ask^^"

[avencherus]

@Zylann That is an interesting point. If you get back a 0 in delta, it is does represent there is/was no time in which to do anything, and anything multiplied by delta 0 is going to do nothing. So why call the function? I am wondering if there are some cases with 0 delta where you'd still want to execute something not dependent on time, but wouldn't want to locate it in the physics process loop.

If the goal is to not surprise people (oh no, game was running fine for weeks, but today crashed because of divide by 0?!) or add extra work to the developer (maintaining code for guarding against 0 in dozens to hundreds of places), it probably shouldn't execute delta <= 0.0, and just be documented it might not execute at all if it's out of time.

[zmanuel]

@avencherus A legitimate case where you would want _process to still be called on zero timesteps is if you want to implement your own framerate statistics, you'd miss render frames. A slightly more contrived example would be old-school fixed timesteps; some game may decide it works best if it engages v-sync and just assumes to get _process-calls 60 times per second. Sure, that means it gets slowdown if frames are missed or the framerate drops to 30 fps, but in some cases that may be preferable to the alternative. I remember reading in a very old shmup review something along the lines of "The game slows down when the action gets too much, but then again, that helps to get through the tougher spots." Ultimately, what I guess I'm saying is that control over the number of physics steps and delta arguments should be given to the game, with reasonable defaults.

@Zylann Negative timesteps are out of the question. Even if you implement your timestep physically accurately, negative steps just reverse the mechanical time, not thermodynamic time. Take your basic fake friction update:
velocity = velocity * exp(-lambda * delta)
with some positive friction strength lambda. Normally, it decreases the velocity and is benign and stable, but if you feed that negative delta, it increases it uncontrollably. For positive delta, it is furthermore perfectly fine to approximate the above update to
velocity = velocity / (1 + lambda * delta)
to avoid a possibly expensive exp call (I guess in GDScript, that does not matter much), and that formula breaks hard at delta < -1/lambda.

Regarding your derivative, you may already be getting problems at small timesteps. I assume you're doing something along the lines

old_value = value
.... (calculate value in some complicated way)
derivative = (value - old_value)/delta
old_value = value

Since old_value and value are likely to be very close, that runs into the old numeric problem of cancellation and elimination of significant digits. The lowest allowed delta argument in the old version of the PR was 1E-6; (single precision) floats are only accurate to about 1E-8, which only leaves your derivative with an accuracy of about 1/100, provided it is of the same size as value, approximately. If it's smaller (say, an object moving at 1 m/s, 100 m away), you're completely out of accuracy.
If possible, and I'm aware it is not always possible, it's better to first calculate the derivative, then update the value with
value = value + derivative * delta
That still has accuracy problems if derivative * delta is much smaller than value, but they don't show as much. And of course, naive application of this leads to exploding physics.
TL;DR: Bailing out on non-positive delta is a valid soluiton :)