search

MirrorNetworking / Mirror

#1 Open Source Unity Networking Library
https://mirror-networking.com
MIT License
5.18k stars 767 forks source link

KCP handles first connection wrong on il2cpp release build #2900

Closed imerr closed 2 years ago

imerr commented 3 years ago

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:

Expected behavior Client connects

Screenshots

https://user-images.githubusercontent.com/1426904/131664456-98bbe6a4-2ad7-4ea9-bafc-f6cbf210bbd6.mp4

here's a video of the issue

Desktop (please complete the following information):

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 commented 3 years ago

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 commented 3 years ago

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:

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):

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 commented 3 years ago

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

miwarnec commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

I'm working with:

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)

image

MrGadget1024 commented 3 years ago

@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 commented 2 years ago

https://github.com/vis2k/Mirror/pull/3030

MrGadget1024 commented 2 years ago

fixed by https://github.com/vis2k/Mirror/pull/3030

gabetoth-alder commented 1 year ago

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?