[UE5.4, connection lost] Connection lost because of GC delete UNetDriver

wukakuki · May 2, 2024, 5:47pm

below is the stack trace and log of a connection to a remote game server.
from the log we can see the FSocketBSD socket fd 277 is closed by GC and it’s used to call sendto when it completed travel to a remote level.

[2024.05.02-17.17.40:173][301]LogSockets: ~FSocketBSD Socket fd: 277
[2024.05.02-17.17.40:182][301]LogStats: FPlatformStackWalk::StackWalkAndDump -  0.009 s
[2024.05.02-17.17.40:182][301]LogOutputDevice: === FDebug::DumpStackTrace(): ===
[2024.05.02-17.17.40:182][301]LogOutputDevice: 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x017adb0c UnrealEditor-Sockets.dylib!FSocketMac::~FSocketMac()   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x017ad92c UnrealEditor-Sockets.dylib!FSocketMac::~FSocketMac()   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x13e9fa64 UnrealEditor-OnlineSubsystemUtils.dylib!UIpConnection::CleanUp()   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x17c2c9e4 UnrealEditor-Engine.dylib!UNetDriver::FinishDestroy()   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x0323a154 UnrealEditor-CoreUObject.dylib!UObject::ConditionalFinishDestroy()   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x030ce978 UnrealEditor-CoreUObject.dylib!IncrementalPurgeGarbage(bool, double)   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x030d6514 UnrealEditor-CoreUObject.dylib!void UE::GC::PostCollectGarbageImpl<true>(EObjectFlags)   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x030d33d4 UnrealEditor-CoreUObject.dylib!UE::GC::FReachabilityAnalysisState::PerformReachabilityAnalysisAndConditionallyPurgeGarbage(bool)   [UnknownFile]) 
[2024.05.02-17.17.40:182][301]LogOutputDevice: [Callstack] 0x030d776c UnrealEditor-CoreUObject.dylib!CollectGarbage(EObjectFlags, bool)   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x1895fc9c UnrealEditor-Engine.dylib!UEngine::TrimMemory()   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x1895b5fc UnrealEditor-Engine.dylib!UEngine::LoadMap(FWorldContext&, FURL, UPendingNetGame*, FString&)   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x18959008 UnrealEditor-Engine.dylib!UEngine::TickWorldTravel(FWorldContext&, float)   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x105feb68 UnrealEditor-UnrealEd.dylib!UEditorEngine::Tick(float, bool)   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x113216fc UnrealEditor-UnrealEd.dylib!UUnrealEdEngine::Tick(float, bool)   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x00cd2100 UnrealEditor!FEngineLoop::Tick()   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x00cdcbd4 UnrealEditor!GuardedMain(char16_t const*)   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x00cf5548 UnrealEditor!-[UEAppDelegate runGameThread:]   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x04c1ec24 UnrealEditor-Core.dylib!-[FCocoaGameThread main]   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x9b028520 Foundation!__NSThread__start__()   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x99e1ef94 libsystem_pthread.dylib!_pthread_start()   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: [Callstack] 0x99e19d34 libsystem_pthread.dylib!thread_start()   [UnknownFile]) 
[2024.05.02-17.17.40:183][301]LogOutputDevice: 
[2024.05.02-17.17.40:184][301]LogSockets: close FSocketBSD Socket fd: 277
[2024.05.02-17.17.40:184][301]LogSockets: close FSocketBSD Socket fd: -1, error: -1
[2024.05.02-17.17.40:235][301]LogUObjectHash: Compacting FUObjectHashTables data took   0.85ms
[2024.05.02-17.17.40:320][301]LogAudio: Display: Audio Device (ID: 2) registered with world 'FirstPersonMap'.
[2024.05.02-17.17.40:320][301]LogWorldMetrics: [Initialize]
[2024.05.02-17.17.40:321][301]LogRenderer: SceneCulling instance hierarchy is disabled as UseNanite(METAL_SM5) returned false, for scene: 'World /Game/FirstPerson/Maps/UEDPIE_1_FirstPersonMap.FirstPersonMap'.
[2024.05.02-17.17.40:321][301]LogWorldPartition: ULevel::OnLevelLoaded(FirstPersonMap)(bIsOwningWorldGameWorld=1, bIsOwningWorldPartitioned=1, InitializeForMainWorld=1, InitializeForEditor=0, InitializeForGame=1)
[2024.05.02-17.17.40:321][301]LogWorldPartition: Display: WorldPartition initialize started...
[2024.05.02-17.17.40:321][301]LogWorldPartition: UWorldPartition::Initialize : World = /Game/FirstPerson/Maps/UEDPIE_1_FirstPersonMap.FirstPersonMap, World Type = PIE, IsMainWorldPartition = 1, Location = V(0), Rotation = R(0), IsEditor = 0, IsGame = 0, IsPIEWorldTravel = 1, IsCooking = 0
[2024.05.02-17.17.40:321][301]LogWorldPartition: UWorldPartition::Initialize Context : World NetMode = Client, IsServer = 0, IsDedicatedServer = 0, IsServerStreamingEnabled = 0, IsServerStreamingOutEnabled = 0, IsUsingMakingVisibleTransaction = 0, IsUsingMakingInvisibleTransaction = 0
[2024.05.02-17.17.40:322][301]LogWorldPartition: Display: GenerateStreaming for 'FirstPersonMap' started...
[2024.05.02-17.17.40:324][301]LogWorldPartition: FSpatialHashSettings::UpdateSettings : UseAlignedGridLevels = 1, SnapNonAlignedGridLevelsToLowerLevels = 1, PlaceSmallActorsUsingLocation = 0, PlacePartitionActorsUsingLocation = 1
[2024.05.02-17.17.40:325][301]LogStreaming: Display: FlushAsyncLoading(60): 58 QueuedPackages, 0 AsyncPackages
[2024.05.02-17.17.40:340][301]LogWorldPartition: Display: GenerateStreaming for 'FirstPersonMap' took 18.159 ms
[2024.05.02-17.17.40:341][301]LogContentBundle: [FirstPersonMap(Client 1)] Creating new container.
[2024.05.02-17.17.40:341][301]LogWorldPartition: Display: WorldPartition initialize took 20.262 ms (total: 61.937 ms)
[2024.05.02-17.17.40:341][301]LogPlayLevel: PIE: World Init took: (0.020982s)
[2024.05.02-17.17.40:343][301]LogWorld: Bringing World /Game/FirstPerson/Maps/UEDPIE_1_FirstPersonMap.FirstPersonMap up for play (max tick rate 0) at 2024.05.03-01.17.40
[2024.05.02-17.17.40:343][301]LogWorld: Bringing up level for play took: 0.002029
[2024.05.02-17.17.40:343][301]LogLoad: Took 0.204011 seconds to LoadMap(/Game/FirstPerson/Maps/FirstPersonMap)
[2024.05.02-17.17.40:343][301]LogGlobalStatus: LoadMap Load map complete /Game/FirstPerson/Maps/FirstPersonMap
[2024.05.02-17.17.40:343][301]LogSockets: send to Socket fd: 277
[2024.05.02-17.17.40:343][301]LogNet: handle socket send result in LowLevelSend with subsystem.
[2024.05.02-17.17.40:352][301]LogStats: FPlatformStackWalk::StackWalkAndDump -  0.008 s
[2024.05.02-17.17.40:352][301]LogOutputDevice: === FDebug::DumpStackTrace(): ===
[2024.05.02-17.17.40:352][301]LogOutputDevice: 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x13ea18d8 UnrealEditor-OnlineSubsystemUtils.dylib!UIpConnection::LowLevelSend(void*, int, FOutPacketTraits&)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x17bec1ec UnrealEditor-Engine.dylib!UNetConnection::FlushNet(bool)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x17edaa28 UnrealEditor-Engine.dylib!UPendingNetGame::SendJoin()   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x17ed86a4 UnrealEditor-Engine.dylib!UPendingNetGame::TravelCompleted(UEngine*, FWorldContext&)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x18959294 UnrealEditor-Engine.dylib!UEngine::TickWorldTravel(FWorldContext&, float)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x105feb68 UnrealEditor-UnrealEd.dylib!UEditorEngine::Tick(float, bool)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x113216fc UnrealEditor-UnrealEd.dylib!UUnrealEdEngine::Tick(float, bool)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x00cd2100 UnrealEditor!FEngineLoop::Tick()   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x00cdcbd4 UnrealEditor!GuardedMain(char16_t const*)   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x00cf5548 UnrealEditor!-[UEAppDelegate runGameThread:]   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x04c1ec24 UnrealEditor-Core.dylib!-[FCocoaGameThread main]   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x9b028520 Foundation!__NSThread__start__()   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x99e1ef94 libsystem_pthread.dylib!_pthread_start()   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: [Callstack] 0x99e19d34 libsystem_pthread.dylib!thread_start()   [UnknownFile]) 
[2024.05.02-17.17.40:352][301]LogOutputDevice: 
[2024.05.02-17.17.40:357][301]LogNet: UIpConnection::HandleSocketSendResult: Socket->SendTo failed with error 10 (SE_ENOTSOCK). [UNetConnection] RemoteAddr: 52.78.188.170:7777, Name: IpConnection_2, Driver: Name:GameNetDriver Def:GameNetDriver IpNetDriver_2, IsServer: NO, PC: NULL, Owner: NULL, UniqueId: NULL:Siqis-MacBook-Pro.local-36F1B2593B424ED8F914098881EAE46A Connection beginning close timeout (Timeout = 5.000000).

any help and thoughts will be appreciated.
Thanks in advance

wukakuki · May 8, 2024, 6:12am

In Engine/Source/Runtime/Sockets/Private/Mac/SocketSubsystemMac.h function Close. replace it with

if (Socket != INVALID_SOCKET)
		{
			int32 error = closesocket(Socket);
			Socket = INVALID_SOCKET;
			return error == 0;
		}
		return false;

EricLoftia · December 12, 2024, 2:20am

Thanks so much for posting the solution, this one looked pretty nightmarish to track down.
For posterity, I was seeing errors like:

Error: UEngine::BroadcastNetworkFailure: FailureType = ConnectionLost, ErrorString = UIpNetDriver::TickDispatch: Socket->RecvFrom: 10 (SE_ENOTSOCK) from 0.0.0.0:0, Driver = Name:GameNetDriver Def:GameNetDriver EOSNetDriver_2147481789
[2024.12.11-22.50.18:715][892]LogNet: Warning: Network Failure: GameNetDriver[ConnectionLost]: UIpNetDriver::TickDispatch: Socket->RecvFrom: 10 (SE_ENOTSOCK) from 0.0.0.0:0
[2024.12.11-22.50.18:715][892]LogNet: NetworkFailure: ConnectionLost, Error: 'UIpNetDriver::TickDispatch: Socket->RecvFrom: 10 (SE_ENOTSOCK) from 0.0.0.0:0'
[2024.12.11-22.50.18:715][892]LogNet: UNetConnection::Close: [UNetConnection] RemoteAddr: 35.212.253.146:46543, Name: EOSIpNetConnection_2147481714, Driver: Name:GameNetDriver Def:GameNetDriver EOSNetDriver_2147481789, IsServer: NO, PC: NULL, Owner: NULL, UniqueId: RedpointEOS:00024d5955254fabb1a7f7bac18b0159, Channels: 3, Time: 2024.12.11-22.50.18
[2024.12.11-22.50.18:715][892]LogNet: UChannel::Close: Sending CloseBunch. ChIndex == 0. Name: [UChannel] ChIndex: 0, Closing: 0 [UNetConnection] RemoteAddr: 35.212.253.146:46543, Name: EOSIpNetConnection_2147481714, Driver: Name:GameNetDriver Def:GameNetDriver EOSNetDriver_2147481789, IsServer: NO, PC: NULL, Owner: NULL, UniqueId: RedpointEOS:00024d5955254fabb1a7f7bac18b0159
[2024.12.11-22.50.18:715][892]LogNet: Error: UEngine::BroadcastNetworkFailure: FailureType = ConnectionLost, ErrorString = UIpNetConnection::HandleSocketSendResult: Socket->SendTo failed with error 10 (SE_ENOTSOCK). [UNetConnection] RemoteAddr: 35.212.253.146:46543, Name: EOSIpNetConnection_2147481714, Driver: Name:GameNetDriver Def:GameNetDriver EOSNetDriver_2147481789, IsServer: NO, PC: NULL, Owner: NULL, UniqueId: RedpointEOS:00024d5955254fabb1a7f7bac18b0159 Connection will be closed during next Tick()!, Driver = Name:GameNetDriver Def:GameNetDriver EOSNetDriver_2147481789
[2024.12.11-22.50.18:715][892]LogIris: Display: Iris ReplicationSystem[0] is about to be destroyed
[2024.12.11-22.50.18:716][892]LogNet: Error: UEngine::BroadcastNetworkFailure: FailureType = ConnectionLost, ErrorString = Your connection to the host has been lost., Driver = Name:GameNetDriver Def:GameNetDriver EOSNetDriver_2147481789
[2024.12.11-22.50.18:716][892]LogNet: Warning: Encountered an error, cleaning up this connection now

And this engine patch fixed it.