View Issue Details

IDProjectCategoryView StatusLast Update
0005331The Dark ModPhysicspublic23.08.2020 07:36
Reporterstgatilov Assigned Tostgatilov  
PrioritynormalSeveritymajorReproducibilitysometimes
Status resolvedResolutionfixed 
Product VersionTDM 2.08 
Target VersionTDM 2.09Fixed in VersionTDM 2.09 
Summary0005331: Doors get stuck sometimes: neither player nor AI can open them
DescriptionSometimes doors get into horribly broken state, where they cannot move at all.
Frobbing it has no effect (no movements, no sounds), AI cannot open it and gets stuck.
Steps To ReproduceHappens very rarely (I cannot reproduce it yet).

See the attached savegame for 2.08 release on "CoS2: A Precarious Position" FM.
Additional InformationOriginally reported by darksilence here:
  https://forums.thedarkmod.com/index.php?/topic/20529-doors-and-other-handles-like-switches-become-unusable-sometimes/
TagsNo tags attached.

Activities

stgatilov

stgatilov

22.08.2020 15:13

administrator   ~0012749

Original savegame by darksilence:
  https://thedarkmod.blob.core.windows.net/various/bugtracker/darksilence_baddoors.save
stgatilov

stgatilov

22.08.2020 15:21

administrator   ~0012750

Last edited: 22.08.2020 15:31

View 3 revisions

The door in question is called: atdm_door_96x48_2hinge_3
It has an entity in m_FrobPeers called: func_static_1130
I assume this entity is the door handle.

Here is the state of the handle:
        m_Open true
        m_bIntentOpen false
        m_StateChange true
        m_bInterruptable false
        m_ClosedAngles {pitch=0.000000000 yaw=0.000000000 roll=0.000000000 }
        m_OpenAngles {pitch=-45.0000000 yaw=0.000000000 roll=0.000000000 }
        m_Rotating true bool
        m_Translating false bool
In idMover:
        move {stage=ACCELERATION_STAGE (0) acceleration=0 movetime=0 ...} idMover::moveStage_s
        rot {stage=FINISHED_STAGE (3) acceleration=0 movetime=112 rot.pitch=-401.785736 ...} idMover::rotationState_s
        dest_angles {pitch=-45.0000000 yaw=0.000000000 roll=0.000000000 } idAngles
        angle_delta {pitch=-401.785736 yaw=0.000000000 roll=0.000000000 } idAngles
And in physics.current:
        time 17070859 int
        atRest 17070859 int
        angles {pitch=-44.9999886 yaw=-90.0000000 roll=0.000000000 } idAngles
        localAngles {pitch=315.000000 yaw=0.000000000 roll=0.000000000 } idAngles
        linearExtrapolation {extrapolationType=EXTRAPOLATION_NONE (1) startTime=0.000000000 duration=0.000000000 ...} idExtrapolate<idVec3>
        angularExtrapolation {extrapolationType=EXTRAPOLATION_LINEAR (2) startTime=17070748.0 duration=112.000000 ...} idExtrapolate<idAngles>
Here is angularExtrapolation inside:
        extrapolationType EXTRAPOLATION_LINEAR (2) extrapolation_t
        startTime 17070748.0 float
        duration 112.000000 float
        startValue {pitch=0.000000000 yaw=0.000000000 roll=0.000000000 } idAngles
        baseSpeed {pitch=0.000000000 yaw=0.000000000 roll=0.000000000 } idAngles
        speed {pitch=-401.785736 yaw=0.000000000 roll=0.000000000 } idAngles
        currentTime -1.00000000 float
        currentValue {pitch=0.000000000 yaw=0.000000000 roll=0.000000000 } idAngles

The current time is:
        time 17294307 int
stgatilov

stgatilov

22.08.2020 15:43

administrator   ~0012751

The biggest problem that I see is that localAngles.pitch has become 315 instead of -45.
Most likely something did not finish because of this.
The angle extrapolation seems to be long finished, as seen from rot.stage = FINISHED_STAGE.

I think what happens is wrong usage of angle normalization functions, perhaps in presence of numeric errors.
For example, this code in idMover::BeginRotation is suspicious, since it can turn -45 into 315:
    physicsObj.GetLocalAngles( ang );
    angle_delta = dest_angles - ang;
    if ( angle_delta.Compare(ang_zero, VECTOR_EPSILON) ) {
        // set our final angles so that we get rid of any numerical inaccuracy
        dest_angles.Normalize360();
        physicsObj.SetAngularExtrapolation( EXTRAPOLATION_NONE, 0, 0, dest_angles, ang_zero, ang_zero );
        stopRotation = false;
        DoneRotating();
        return;
    }

The code in CBinaryFrobMover::IsAtOpenPosition and CBinaryFrobMover::IsAtClosedPosition is definitely wrong in case of numeric errors:
    const idAngles& localAngles = physicsObj.GetLocalAngles();
    // greebo: Let the check be slightly inaccurate (use the standard epsilon).
    return (localAngles - m_OpenAngles).Normalize360().Compare(ang_zero, VECTOR_EPSILON) &&
           localOrg.Compare(m_OpenOrigin, VECTOR_EPSILON);
Obviously, if different is slightly less than zero, then this condition does not hold.
It should be Normalize180 here, not Normalize360.

So it might have happened that some rotation did not finish exactly, so the value was slightly less than m_OpenAngles.
Then IsAtOpenPosition returned false, hence idMover::BeginRotation was started, which turned the angle into 315.
It might also be that uncapped FPS has made this issue trigger, since it has randomized timesteps, leading to randomized numeric errors.
stgatilov

stgatilov

22.08.2020 15:58

administrator   ~0012752

One more interesting fact is that idCurve<type>::GetCurrentValue takes global time as float.
So when time is 17294307 (i.e. 5 hours have passed), rounding to float can give 1-2 ms of error!
For this reason, the problem can start happening only after very long time in-game...
stgatilov

stgatilov

22.08.2020 16:30

administrator   ~0012753

I found way to reproduce.

1) Set Uncapped FPS to ON.
2) Start FM.
3) noclip & notarget
4) setviewpos -1230 300 90
5) Pause the game in MSVC debugger and change gameLocal.time to 20000000 in watch.
6) Continue game
7) Go to the door and frob it repeatedly.
After a few attemps the handle will get stuck.
stgatilov

stgatilov

22.08.2020 16:40

administrator   ~0012754

However, most of my guesses are wrong.
Mainly, it is normal for localAngles to become 315. It is normalized to 0..360 interval on every update, so value -45 is impossible.
Thus, the code in idMover::BeginRotation is not wrong to do Normalize360. In fact, debugging shows that it is never executed (while doors get broken).
stgatilov

stgatilov

23.08.2020 04:32

administrator   ~0012755

Added commands getGameTime and setGameTime in svn rev 8944.

The issue can now be reproduced like this:
1) Start Bakery Job FM.
2) Execute: notarget
3) Come to front door and unlock it.
4) Execute: setGameTime 20000000
5) Open/close the door until it gets stuck.
stgatilov

stgatilov

23.08.2020 07:36

administrator   ~0012756

Added sequence file to reproduce the problem with automation in svn rev 16007.
It sets game time to 200M (it's about 55 hours in-game) --- that's ten times worse than what original complaint had.
At such time, any door gets stuck from the first try.

Fixed the problem in svn rev 8946 by switching idInterpolate and idExtrapolate to double precision.
Note that only values which store absolute time are converted: various durations and deltas remain in single precision.
These classes control movement of the door, and they gave enough error at high time to break door handling code.
With this change, opening and closing the door 100 times at gametime = 200M works properly.

I have checked that nothing performance-critical uses these classes (e.g. it is NOT used for particles), so this change won't decrease performance.

Also committed a change in svn rev 8945 to make IsAtOpenPosition and IsAtClosedPosition more reliable.

Issue History

Date Modified Username Field Change
22.08.2020 15:09 stgatilov New Issue
22.08.2020 15:09 stgatilov Status new => assigned
22.08.2020 15:09 stgatilov Assigned To => stgatilov
22.08.2020 15:13 stgatilov Note Added: 0012749
22.08.2020 15:21 stgatilov Note Added: 0012750
22.08.2020 15:23 stgatilov Note Edited: 0012750 View Revisions
22.08.2020 15:31 stgatilov Note Edited: 0012750 View Revisions
22.08.2020 15:43 stgatilov Note Added: 0012751
22.08.2020 15:58 stgatilov Note Added: 0012752
22.08.2020 16:30 stgatilov Note Added: 0012753
22.08.2020 16:40 stgatilov Note Added: 0012754
23.08.2020 04:32 stgatilov Note Added: 0012755
23.08.2020 07:36 stgatilov Note Added: 0012756
23.08.2020 07:36 stgatilov Status assigned => resolved
23.08.2020 07:36 stgatilov Resolution open => fixed
23.08.2020 07:36 stgatilov Fixed in Version => TDM 2.09