KCP handles first connection wrong on il2cpp release build

[imerr]

Edit by MrG: As discovered by cooper (see comment below): turning off NonAlloc in KCP Transport inspector avoids this bug.

Edit by MrG: Happens on windows server builds too. See comment below.

Describe the bug
When attempting to connect to a linux server built with il2cpp "release" using the kcp transport the first connection attempt is not handled correctly and fails

How can we reproduce the issue, step by step:

• Make a linux server build using il2cpp as the scripting backend in "Release" mode or higher of any of the mirror examples (I used tanks, pong has also been tested by the original reporter on discord)
• Run server build & attempt to connect (with unity editor is fine, dont need a client build)
• Expect to be connected, but the server will print "KCP: received unreliable message in state Connected. Disconnecting the connection."
• Disconnect and attempt to reconnect again, and it should work flawlessly from there on out

Expected behavior
Client connects

Screenshots

2021-09-01_13-17-00_6z5avsWfQz.mp4

here's a video of the issue

Desktop (please complete the following information):

• OS: Windows
• Build target: Linux IL2CPP in "Release" or "Master" mode
• Unity version: 2020.3 (although reporting user has tested this with 2019.x as well)
• Mirror branch: master which is 46.0.3 as of writing this (version 44.0.2 was also confirmed to have this issue)

Additional context
Works fine on mono and windows il2cpp does not seem to have the issue.
il2cpp on "debug" mode seems to work fine, just release &

[imerr]

I'm a bit lost on where to start debugging this tbh, i tried valgrinding, but there's too much spam about using uninitialized values in general its pointless to check if it's doing something weird
could try to include just kcp in an empty unity project and see if its reproducable to throw a bug report at unity, but I don't really have to time to do that today (my hunch is an il2cpp/compiler bug seeing it only happens on release..)

[MrGadget1024]

Broken on Windows too

Describe the bug
Host client is fine. First remote client connects but hangs for 10 seconds and disconnects.
Telepathy also works correctly - bug only shows for KCP transport.

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

• Build Basic example as Server Build with IL2CPP selected in Project Settings
• Enter play mode in editor, click Client
• Client never shows player object, disconnects in 10 seconds
• Click Client again...client works normally on 2nd and subsequent attempts

Note that console shows KCP: received unreliable message in state Connected. Disconnecting the connection. 5 times before actually kicking the client (Ping messages every 2 seconds).

Expected behavior
First client to connect should work normally

Desktop (please complete the following information):

• OS: Windows
• Build target: standalone IL2CPP
• Unity version: 2019 LTS, 2020 LTS, 2021 LTS all exhibit the bug
• Mirror branch: master

Headless Server Console Output for single client

KCP: received unreliable message in state Connected. Disconnecting the connection.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
System.Action`1:Invoke(T)
kcp2k.KcpConnection:RawInput(Byte[], Int32)
kcp2k.KcpServer:TickIncoming()
Mirror.NetworkLoop:NetworkEarlyUpdate()
UnityEngine.LowLevel.UpdateFunction:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39)

KCP: received unreliable message in state Connected. Disconnecting the connection.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
System.Action`1:Invoke(T)
kcp2k.KcpConnection:RawInput(Byte[], Int32)
kcp2k.KcpServer:TickIncoming()
Mirror.NetworkLoop:NetworkEarlyUpdate()
UnityEngine.LowLevel.UpdateFunction:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39)

KCP: received unreliable message in state Connected. Disconnecting the connection.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
System.Action`1:Invoke(T)
kcp2k.KcpConnection:RawInput(Byte[], Int32)
kcp2k.KcpServer:TickIncoming()
Mirror.NetworkLoop:NetworkEarlyUpdate()
UnityEngine.LowLevel.UpdateFunction:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39)

KCP: received unreliable message in state Connected. Disconnecting the connection.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
System.Action`1:Invoke(T)
kcp2k.KcpConnection:RawInput(Byte[], Int32)
kcp2k.KcpServer:TickIncoming()
Mirror.NetworkLoop:NetworkEarlyUpdate()
UnityEngine.LowLevel.UpdateFunction:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39)

KCP: received unreliable message in state Connected. Disconnecting the connection.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
System.Action`1:Invoke(T)
kcp2k.KcpConnection:RawInput(Byte[], Int32)
kcp2k.KcpServer:TickIncoming()
Mirror.NetworkLoop:NetworkEarlyUpdate()
UnityEngine.LowLevel.UpdateFunction:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39)

KCP: Connection timed out after not receiving any message for 10000ms. Disconnecting.
UnityEngine.Logger:Log(LogType, Object)
UnityEngine.Debug:LogWarning(Object)
System.Action`1:Invoke(T)
kcp2k.KcpConnection:HandleTimeout(UInt32)
kcp2k.KcpConnection:TickIncoming_Authenticated(UInt32)
kcp2k.KcpConnection:TickIncoming()
kcp2k.KcpServer:TickIncoming()
Mirror.NetworkLoop:NetworkEarlyUpdate()
UnityEngine.LowLevel.UpdateFunction:Invoke()

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39)

[cxxpxr]

Tested with @MrGadget1024 in discord, you can fix this by turning off "NonAlloc" in the KCP settings in the transport component.

[miwarnec]

can you guys try to
#if ENABLE_IL2CPP
nonalloc=false
#endif

and see if that works automatically then - with nonalloc being enabled by default still

[MrGadget1024]

can you guys try to
#if ENABLE_IL2CPP
nonalloc=false
#endif

and see if that works automatically then - with nonalloc being enabled by default still

sure - where should that be inserted?

[pixelpax]

I'm working with:

• Unity 2020.3.17f1
• Mirror 46.0.4
• Windows 10

And getting the same error. Wanted to add a report because in my case, turning off non-alloc does not resolve the issue. I'm using the "dual editor" hack (two projects with symlinked Assets/ and ProjectSettings/) which is where the logs come from, but I also tried with a built standalone server.

Telepathy does work for me in this case and I have no custom messages which would be firing (everything is [Command] and [SyncVar] at this point)

[MrGadget1024]

@pixelpax looks like you've also made Network Manager a child of something in the scene...it has to be at scene root or turn off Dont Detroy On Load (DDOL) in network manager. Either that or you've some other object that's a child of something else trying to invoke DDOL.

[miwarnec]

#3030

[MrGadget1024]

fixed by #3030

[gabetoth-alder]

Hello,

I am getting something similar with a server running on linux. I don't how it affects the users, I just checked the logs and it happens from time to time, usually in bursts. One burst happened for 17 seconds, flooding the log with this. I don't know the frequency though, I only had timestamps for my own logs.

NullReferenceException: Object reference not set to an instance of an object
  at kcp2k.KcpConnection.RawInput (System.Byte[] buffer, System.Int32 msgLength) [0x000a9] in <67124e2008334eddb58d49b12256d278>:0 
  at kcp2k.KcpServer.TickIncoming () [0x00082] in <67124e2008334eddb58d49b12256d278>:0 
  at kcp2k.KcpTransport.ServerEarlyUpdate () [0x00008] in <5cb4c5c2435042f6920ba2cbd55950bd>:0 
  at Mirror.NetworkServer.NetworkEarlyUpdate () [0x00028] in <53972d59d5494013ac695928748cbb60>:0 
  at Mirror.NetworkLoop.NetworkEarlyUpdate () [0x00000] in <53972d59d5494013ac695928748cbb60>:0 
UnityEngine.DebugLogHandler:Internal_LogException(Exception, Object)
UnityEngine.DebugLogHandler:LogException(Exception, Object)
Framework.Core.Managers.ServerLogHandler:LogException(Exception, Object)
UnityEngine.Logger:LogException(Exception, Object)
UnityEngine.Debug:CallOverridenDebugHandler(Exception, Object)

Unity 20.3.41f
Built on Windows 11 for Linux, running on AMAZON_LINUX_2 (AWS/GameLift)
Mirror v2022.10.0 (from AssetStore)

Edit: attached log file.
1.log

Edit2: @MrGadget1024 Can you please verify that is my issue related?