NetworkTransformReliable on child game object got doubled position when CmdTeleport in Start

[DiscreteTom]

Describe the bug

Add a NetworkTransformReliable on a child game object of the player, and set it's local position to non-zero (in my case, set y to 1.5). Then call CmdTeleport in Start to reset its position (in my case:

var nt = this.GetComponent<NetworkTransformReliable>();
        if (this.isOwned)
            nt.CmdTeleport(new Vector3(0, 1.5f, 0));

Then, start the server (which will spawn a player A), and start a client to connect to the server (which will spawn a player B), the player B's position.y is 3 instead of 1.5, but the player A's position is correct.

[IMPORTANT] How can we reproduce the issue, step by step:

I created a minimal repro repo: https://github.com/DiscreteTom/MirrorTest

Build the demo, start the server in unity editor window, then start a standalone client, connect to the server, you can see in unity editor the client's player's child's position.y is 3 instead of 1.5.

Expected behavior

I teleport the child's game object's position.y to 1.5, it should be 1.5.

Screenshots

As you can see, there are 2 players, the connId=0 player's position is correct, but the other player's position is doubled.

Desktop (please complete the following information):

• OS: [e.g. Windows, MacOS] Windows
• Build target: [e.g. Android, webgl, standalone, iOS] Standalone
• Unity version: [e.g. 2017.4] 2021.3.15 & 2022.3.4
• Mirror branch: [e.g. master, 2018] 81.4.0, from unity asset store.

[DiscreteTom]

Maybe related to #3584

[DiscreteTom]

This issue seems to appear randomly, but it looks like the CmdTeleport in Start set the target's position before there is any server snapshots, thus when calculating delta position the position is doubled.

A workaround is not to use teleport in Start. It would be nice to address this in doc if my idea is right.

[DiscreteTom]

With more tests, the position will randomly be doubled when teleport even the teleport is not called in Start. Is the teleport an unstable function?

[miwarnec]

checking thanks

[miwarnec]

excellent repro @DiscreteTom . looking into it now

[miwarnec]

debugging

[miwarnec]

here's where the 3.0 comes from:

AddSnapshot: 8.81628520800635 (0.00, 3.00, 0.00) (0.00000, 0.00000, 0.00000, 1.00000) (1.00, 1.00, 1.00)
UnityEngine.Debug:Log (object)
Mirror.NetworkTransformBase:AddSnapshot (System.Collections.Generic.SortedList`2<double, Mirror.TransformSnapshot>,double,System.Nullable`1<UnityEngine.Vector3>,System.Nullable`1<UnityEngine.Quaternion>,System.Nullable`1<UnityEngine.Vector3>) (at Assets/Mirror/Components/NetworkTransform/NetworkTransformBase.cs:199)
Mirror.NetworkTransformReliable:OnClientToServerSync (System.Nullable`1<UnityEngine.Vector3>,System.Nullable`1<UnityEngine.Quaternion>,System.Nullable`1<UnityEngine.Vector3>) (at Assets/Mirror/Components/NetworkTransform/NetworkTransformReliable.cs:332)
Mirror.NetworkTransformReliable:OnDeserialize (Mirror.NetworkReader,bool) (at Assets/Mirror/Components/NetworkTransform/NetworkTransformReliable.cs:294)
Mirror.NetworkBehaviour:Deserialize (Mirror.NetworkReader,bool) (at Assets/Mirror/Core/NetworkBehaviour.cs:1297)
Mirror.NetworkIdentity:DeserializeServer (Mirror.NetworkReader) (at Assets/Mirror/Core/NetworkIdentity.cs:1060)
Mirror.NetworkServer:OnEntityStateMessage (Mirror.NetworkConnectionToClient,Mirror.EntityStateMessage) (at Assets/Mirror/Core/NetworkServer.cs:351)
Mirror.NetworkMessages/<>c__DisplayClass9_0`2<Mirror.EntityStateMessage, Mirror.NetworkConnectionToClient>:<WrapHandler>g__Wrapped|0 (Mirror.NetworkConnectionToClient,Mirror.EntityStateMessage,int) (at Assets/Mirror/Core/NetworkMessages.cs:210)
Mirror.NetworkMessages/<>c__DisplayClass8_0`2<Mirror.EntityStateMessage, Mirror.NetworkConnectionToClient>:<WrapHandler>b__0 (Mirror.NetworkConnection,Mirror.NetworkReader,int) (at Assets/Mirror/Core/NetworkMessages.cs:183)
Mirror.NetworkServer:UnpackAndInvoke (Mirror.NetworkConnectionToClient,Mirror.NetworkReader,int) (at Assets/Mirror/Core/NetworkServer.cs:620)
Mirror.NetworkServer:OnTransportData (int,System.ArraySegment`1<byte>,int) (at Assets/Mirror/Core/NetworkServer.cs:685)
kcp2k.KcpTransport:<Awake>b__29_6 (int,System.ArraySegment`1<byte>,kcp2k.KcpChannel) (at Assets/Mirror/Transports/KCP/KcpTransport.cs:127)
kcp2k.KcpServer/<>c__DisplayClass20_0:<CreateConnection>b__0 (System.ArraySegment`1<byte>,kcp2k.KcpChannel) (at Assets/Mirror/Transports/KCP/kcp2k/highlevel/KcpServer.cs:262)
kcp2k.KcpServerConnection:OnData (System.ArraySegment`1<byte>,kcp2k.KcpChannel) (at Assets/Mirror/Transports/KCP/kcp2k/highlevel/KcpServerConnection.cs:56)
kcp2k.KcpPeer:TickIncoming_Authenticated (uint) (at Assets/Mirror/Transports/KCP/kcp2k/highlevel/KcpPeer.cs:395)
kcp2k.KcpPeer:TickIncoming () (at Assets/Mirror/Transports/KCP/kcp2k/highlevel/KcpPeer.cs:439)
kcp2k.KcpServer:TickIncoming () (at Assets/Mirror/Transports/KCP/kcp2k/highlevel/KcpServer.cs:369)
kcp2k.KcpTransport:ServerEarlyUpdate () (at Assets/Mirror/Transports/KCP/KcpTransport.cs:220)
Mirror.NetworkServer:NetworkEarlyUpdate () (at Assets/Mirror/Core/NetworkServer.cs:1808)
Mirror.NetworkLoop:NetworkEarlyUpdate () (at Assets/Mirror/Core/NetworkLoop.cs:192)

[miwarnec]

looks like this is a bit of a race condition:

  client OnSerialize writes delta
  server OnDeserialize reads delta

  client calls CmdTeleport
  server OnTeleport calls Reset(), which resets lastDeserialized to 0

  client OnSerialize writes delta (client didn't get RpcTeleport yet, so it didn't reset lastSerialized =0 yet)
  server OnDeserialize reads delta based on old client position before teleport
    server sets pos = last + delta which is off