wolveix / satisfactory-server

A Dockerized version of the Satisfactory dedicated server
https://hub.docker.com/r/wolveix/satisfactory-server
MIT License
1.41k stars 155 forks source link

Client times out upon joining dedicated server #149

Closed abernardi597 closed 2 years ago

abernardi597 commented 2 years ago

Describe the Bug Trying to join the dedicated server, and I'm met with a timeout / reliable buffer overflow.

This seems to occurs regardless of setting -e AUTOPAUSE=false or changing my client connection timeout to 300s, so I don't believe it's related to #143.

Your Runtime Command or Docker Compose File

podman create -t --name satisfactory -h satisfactory-server -p 7777:7777/udp -p 15000:15000/udp -p 15777:15777/udp -v ./satisfactory/:/config --pull always docker.io/wolveix/satisfactory-server:latest

Then podman start satisfactory.

System Specs:

===== START ISSUE REPORT =====
OS:  Linux osaka 5.15.0-48-generic #54-Ubuntu SMP Fri Aug 26 13:26:29 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
CPU: Intel(R) Core(TM) i7-6700 CPU @ 3.40GHz
RAM: 15GB/15GB
HDD: 20GB/233GB (9% used)
===== END ISSUE REPORT =====

Additional Context The server seems to give up on the first client connection after this (despite AUTOPAUSE=false and a client timeout of 300s):

[2022.09.28-01.35.40:676][659]LogNet: UNetDriver::TickDispatch: Very long time between ticks. DeltaTime: 18.46, Realtime: 18.46. IpNetDriver_2147480495
[2022.09.28-01.35.40:676][659]LogNet: UNetDriver::TickDispatch: Very long time between ticks. DeltaTime: 18.46, Realtime: 18.46. EOSNetDriver_2147482293
[2022.09.28-01.35.43:851][912]LogNetSerialization: Error: FBitWriter overflowed! (WriteLen: -1, Remaining: 7255, Max: 7255)
[2022.09.28-01.35.43:851][912]LogNet: Warning: Closing connection. Can't send function 'Multicast_RepActionState' on 'BPCA_EatCreatureFood_C /Game/FactoryGame/Map/GameLevel01/Persistent_Level.Persistent_Level:PersistentLevel.Char_SpaceRabbit_C_2147089928.BPCA_EatCreatureFood_C_0': Reliable buffer overflow. FieldCache->FieldNetIndex: 0 Max 2. Ch MaxPacket: 1024.
[2022.09.28-01.35.43:851][912]LogNet: UNetConnection::Close: [UNetConnection] RemoteAddr: 10.0.2.100:60844, Name: IpConnection_2147480476, Driver: GameNetDriver EOSNetDriver_2147482293, IsServer: YES, PC: BP_PlayerController_C_2147479429, Owner: BP_PlayerController_C_2147479429, UniqueId: EOS:(EOS)d0977cad89ee471e92273617cfae574b|00024f5c53d142f1b77391fe8a942b14, Channels: 1790, Time: 2022.09.28-01.35.43
[2022.09.28-01.35.43:851][912]LogNet: UChannel::Close: Sending CloseBunch. ChIndex == 0. Name: [UChannel] ChIndex: 0, Closing: 0 [UNetConnection] RemoteAddr: 10.0.2.100:60844, Name: IpConnection_2147480476, Driver: GameNetDriver EOSNetDriver_2147482293, IsServer: YES, PC: BP_PlayerController_C_2147479429, Owner: BP_PlayerController_C_2147479429, UniqueId: EOS:(EOS)d0977cad89ee471e92273617cfae574b|00024f5c53d142f1b77391fe8a942b14

Further attempts to login have a vaguely similar warning and still result in a timeout:

[2022.09.28-01.57.23:826][761]LogNetPartialBunch: Warning: SendBunch: Reliable partial bunch overflows reliable buffer! [UActorChannel] Actor: Char_SpaceRabbit_C /Game/FactoryGame/Map/GameLevel01/Persistent_Level.Persistent_Level:PersistentLevel.Char_SpaceRabbit_C_2147089928, Role: 3, RemoteRole: 1 [UChannel] ChIndex: 12, Closing: 0 [UNetConnection] RemoteAddr: 10.0.2.100:54799, Name: IpConnection_2147472143, Driver: GameNetDriver EOSNetDriver_2147482293, IsServer: YES, PC: BP_PlayerController_C_2147472136, Owner: BP_PlayerController_C_2147472136, UniqueId: EOS:(EOS)d0977cad89ee471e92273617cfae574b|00024f5c53d142f1b77391fe8a942b14
[2022.09.28-01.57.23:826][761]LogNetPartialBunch: Warning:    Num OutgoingBunches: 2. NumOutRec: 254
[2022.09.28-01.57.23:827][761]LogNet: UNetConnection::Close: [UNetConnection] RemoteAddr: 10.0.2.100:54799, Name: IpConnection_2147472143, Driver: GameNetDriver EOSNetDriver_2147482293, IsServer: YES, PC: BP_PlayerController_C_2147472136, Owner: BP_PlayerController_C_2147472136, UniqueId: EOS:(EOS)d0977cad89ee471e92273617cfae574b|00024f5c53d142f1b77391fe8a942b14, Channels: 1540, Time: 2022.09.28-01.57.23
[2022.09.28-01.57.23:827][761]LogNet: UChannel::Close: Sending CloseBunch. ChIndex == 0. Name: [UChannel] ChIndex: 0, Closing: 0 [UNetConnection] RemoteAddr: 10.0.2.100:54799, Name: IpConnection_2147472143, Driver: GameNetDriver EOSNetDriver_2147482293, IsServer: YES, PC: BP_PlayerController_C_2147472136, Owner: BP_PlayerController_C_2147472136, UniqueId: EOS:(EOS)d0977cad89ee471e92273617cfae574b|00024f5c53d142f1b77391fe8a942b14
[2022.09.28-01.57.23:837][762]LogFactory: Warning: Put down failed because we where never equipped.
[2022.09.28-01.57.23:837][762]LogFactory: Warning: Put down failed because we where never equipped.
[2022.09.28-01.57.23:837][762]LogOnlineSession: Warning: OSS: EOS-OSS: No game present to leave for session (GameSession)
wolveix commented 2 years ago

Please see #143 and #144

https://questions.satisfactorygame.com/post/632d2441ca608e080351fb69

abernardi597 commented 2 years ago

I read #143 and #144 before opening this issue, and I would like to re-iterate that this is not solved by turning off autopause, so it does not appear to be related to me.

Moreover, the machine that the server is running on does seem to load the world before the timeout occurs (you can see the delta time is 18.46 in the logs I added, which should be close to the time taken to load the world).

If this would be better added to the discussion on #143 I can re-post there, but I don't think this is the same issue.

wolveix commented 2 years ago

@abernardi597 my apologies, it is very late here :) I'm assuming that your system specs were recorded while the server was running, as otherwise your RAM would be largely insufficient.

I will look into your issue as soon as possible! But please do read over the other two linked issues, as Update 6 introduced many issues/changes within the server space.

abernardi597 commented 2 years ago

No problem, just didn't want it to get swept under the rug!

If I'm not mistaken, the command in the template reports MemAvailable / MemTotal: RAM: $(awk '/MemAvailable/ {printf( "%d\n", $2 / 1024000 )}' /proc/meminfo)GB/$(awk '/MemTotal/ {printf( "%d\n", $2 / 1024000 )}' /proc/meminfo)GB This would reflect that nothing of note was running on my machine.

abernardi597 commented 2 years ago

This may have been fixed by the latest patch. I was able to log into the server normally after a single failed attempt (the client crashed during the connection). This was with autopause enabled.