search

valheimPlus / ValheimPlus

A HarmonyX Mod aimed at improving the gameplay and quality of life of the game Valheim.
http://valheim.plus
GNU Affero General Public License v3.0
967 stars 236 forks source link

[BUG] Disconnected from server when Valheim Plus is installed/enabled. LGSM & AWS EC2 hosted Ubuntu server. #714

Closed baconinthemorn closed 2 years ago

baconinthemorn commented 2 years ago

Describe the bug

I am hosting my Valheim server on AWS (Linux-Ubuntu) installed via LGSM (https://linuxgsm.com/servers/vhserver/). I have installed Valheim+ using the LGSM command mods-install to install the mod and the install itself seems to go just fine. I have installed V+ on my localhost (client) and I am able to connect successfully to my server.

After a few minutes, I begin to see a connection problem icon in the top left of my HUD (in game) and eventually get Disconnected from the server. After further reviewing my server logs, it appears something is issuing an exit command or an error is causing the server to stop and LGSM restarts the server (allowing me to log back in immediately).

10/31/2022 03:42:55: Game server connected
10/31/2022 03:42:55: UI Group status changed Menu = True

Unloading 16 unused Assets to reduce memory usage. Loaded Objects now: 105987.
Total: 111.076793 ms (FindLiveObjects: 5.370955 ms CreateObjectMapping: 17.904038 ms MarkObjects: 87.536839 ms  DeleteObjects: 0.263957 ms)

Unloading 6 Unused Serialized files (Serialized files now loaded: 1)
UnloadTime: 11.525934 ms
HDR Render Texture not supported, disabling HDR on reflection probe.
HDR Render Texture not supported, disabling HDR on reflection probe.
10/31/2022 03:42:55: Using default prefs
10/31/2022 03:42:55: isModded: False
10/31/2022 03:42:55: Zonesystem Awake 486
10/31/2022 03:42:55: DungeonDB Awake 486
10/31/2022 03:42:55: Registering lobby
10/31/2022 03:42:59: Audioman already exist, destroying self

Unloading 527 unused Assets to reduce memory usage. Loaded Objects now: 106394.
Total: 126.449129 ms (FindLiveObjects: 5.504693 ms CreateObjectMapping: 17.417733 ms MarkObjects: 101.822988 ms  DeleteObjects: 1.702919 ms)

10/31/2022 03:43:04: Zonesystem Start 486
10/31/2022 03:43:04: Added 3 locations, 0 vegetations, 0 environments, 0 biome env-setups from locations_cp1
10/31/2022 03:43:04: Added 1 locations, 0 vegetations, 1 environments, 0 biome env-setups from locations_mountaincaves
10/31/2022 03:43:05: DungeonDB Start 486
10/31/2022 03:43:05: ZRpc timeout set to 30s
10/31/2022 03:43:05: Load world: Cold (Cold)
10/31/2022 03:43:05: Loading 46045 zdos , my id 1370096213 data version:28
10/31/2022 03:43:05: Loaded 2932 dead zdos
10/31/2022 03:43:05: Removed 0 OLD generated ZDOS
10/31/2022 03:43:05: Loaded 7513 locations
The shader Hidden/Dof/DepthOfFieldHdr (UnityEngine.Shader) on effect Main Camera (UnityStandardAssets.ImageEffects.DepthOfField) is not supported on this platform!
The image effect Main Camera (UnityStandardAssets.ImageEffects.DepthOfField) has been disabled as it's not supported on the current platform.
The shader Hidden/SunShaftsComposite (UnityEngine.Shader) on effect Main Camera (UnityStandardAssets.ImageEffects.SunShafts) is not supported on this platform!
The shader Hidden/SimpleClear (UnityEngine.Shader) on effect Main Camera (UnityStandardAssets.ImageEffects.SunShafts) is not supported on this platform!
The image effect Main Camera (UnityStandardAssets.ImageEffects.SunShafts) has been disabled as it's not supported on the current platform.
10/31/2022 03:43:49: Got status changed msg k_ESteamNetworkingConnectionState_Connecting
10/31/2022 03:43:49: New connection
10/31/2022 03:43:49: Accepting connection k_EResultOK
10/31/2022 03:43:49: Connecting to Steamworks.SteamNetworkingIdentity
10/31/2022 03:43:49: Got status changed msg k_ESteamNetworkingConnectionState_Connected
10/31/2022 03:43:49: Connected
10/31/2022 03:43:49: Got connection SteamID 76561197960923683
10/31/2022 03:43:49: Got handshake from client 76561197960923683
10/31/2022 03:44:07: VERSION check their:0.211.11@0.9.9.9  mine:0.211.11@0.9.9.9
10/31/2022 03:44:07: Server: New peer connected,sending global keys
10/31/2022 03:44:10: VPlus configuration synced to peer #2178034004
10/31/2022 03:44:21: Got character ZDOID from Nolyn : 2178034004:1
10/31/2022 03:44:30: Found location of type Eikthyrnir
10/31/2022 03:45:38: Placed locations in zone 2,-6  duration 4.516 ms
10/31/2022 03:45:38: Placed locations in zone 2,-5  duration 25.573 ms
10/31/2022 03:46:04: Placed locations in zone -4,-12  duration 10.583 ms
10/31/2022 03:46:04: Placed locations in zone -3,-12  duration 1.202 ms
10/31/2022 03:47:00: Placed locations in zone -8,-13  duration 18.952 ms
10/31/2022 03:47:00: Placed locations in zone -7,-13  duration 0.131 ms
10/31/2022 03:47:00: Placed locations in zone -6,-13  duration 7.286 ms
10/31/2022 03:47:02: Placed locations in zone -9,-13  duration 41.762 ms
10/31/2022 03:47:20: Placed locations in zone -8,-14  duration 2.681 ms
10/31/2022 03:47:50: Placed locations in zone -8,-15  duration 2.72 ms
^CFallback handler could not load library /home/vhserver/serverfiles/valheim_server_Data/Mono/libparty
Fallback handler could not load library /home/vhserver/serverfiles/valheim_server_Data/Mono/libparty.so
Fallback handler could not load library /home/vhserver/serverfiles/valheim_server_Data/Mono/party
Fallback handler could not load library /home/vhserver/serverfiles/valheim_server_Data/Mono/libparty
Fallback handler could not load library /home/vhserver/serverfiles/valheim_server_Data/Mono/libparty.so
Fallback handler could not load library /home/vhserver/serverfiles/valheim_server_Data/Mono/libparty
10/31/2022 03:51:43: Game - OnApplicationQuit
10/31/2022 03:51:43: Shuting down
10/31/2022 03:51:43: ZNet Shutdown
10/31/2022 03:51:43: clone 103
10/31/2022 03:51:43: World save writing starting
10/31/2022 03:51:43: World save writing started
10/31/2022 03:51:43: Saved 52000 zdos
10/31/2022 03:51:43: World save writing finishing
10/31/2022 03:51:43: World save writing finished
10/31/2022 03:51:43: Considering autobackup. World time: 517.36, short time: 7200, long time: 43200, backup count: 4
10/31/2022 03:51:43: Skipping backup. World session not long enough.
10/31/2022 03:51:43: World saved ( 203.339ms )
10/31/2022 03:51:43: Considering autobackup. World time: 517.36, short time: 7200, long time: 43200, backup count: 4
10/31/2022 03:51:43: Skipping backup. World session not long enough.
10/31/2022 03:51:43: Sending disconnect msg
10/31/2022 03:51:43: Sent to 76561197960923683
10/31/2022 03:51:43: Disposing socket
10/31/2022 03:51:43: Stopping listening socket
10/31/2022 03:51:43: Disposing socket
10/31/2022 03:51:43: Closing socket 76561197960923683
10/31/2022 03:51:43:   send queue size:0
10/31/2022 03:51:43: Last socket, unregistering callback
10/31/2022 03:51:43: ZSteamSocket  UnregisterGlobalCallbacks, existing sockets:0
10/31/2022 03:51:43: Disposing socket
10/31/2022 03:51:43: Last socket, unregistering callback
10/31/2022 03:51:43: ZSteamSocket  UnregisterGlobalCallbacks, existing sockets:0
Setting up 1 worker threads for Enlighten.
  Thread -> id: 7f409dffd700 -> priority: 1
10/31/2022 03:51:46: Steam manager on destroy
10/31/2022 03:51:46: ZNet OnDestroy
10/31/2022 03:51:46: Net scene destroyed

To Reproduce

Steps for the devs to reproduce the behavior:

  1. Install Valheim Server via LGSM
  2. Install Valheim+ Mod via the mod-install command
  3. Update executable to start_server_bepinex.sh
  4. Update valheim_plus.cfg to enable torches & fire sections.
  5. Start Valheim Server
  6. Connect to server
  7. Play as usual
  8. After a few minutes, all users are disconnected from the server, seemingly because the server crashed.

Expected behavior

Remain connected to server without restart/disconnect

Troubleshooting

Screenshots

image

Additional context

I have no other mods installed at all, just a vanilla installation via LGSM hosted on AWS EC2 t3.medium instance. Any insight or feedback would be greatly appreciated. I play this game with my father and we would love to make use of some of the quality of life features this mod provides (especially a shared map). If I uninstall the mod and play normal vanilla I am not observing this issue at all.

Angeal87 commented 2 years ago

I have the same configuration. V+ was installed via LGSM command mod-install. I have no problems. However, I use a local server at my home.

baconinthemorn commented 2 years ago

Damn, well that's good to know at least! I guess I could go full send and just rebuild the instance with a new storage volume to start from scratch with a fresh install of LGSM, Valheim, then the mod... but that's a bit more heavy handed than I'd like to go unless it's the only option as I'd have to migrate any world files and configs

Angeal87 commented 2 years ago

Are all dependencies installed? libc6-dev for example?

baconinthemorn commented 2 years ago

Yeah, I verified it was installed: libc6-dev is already the newest version (2.35-0ubuntu3.1).

I just spun up a new (fresh) instance completely from scratch and the same behavior is taking place with this new instance as well, completely fresh LGSM + Valheim + Valheim+, only enabled the torch mod via valheim_plus.cfg. Super strange... it doesn't even seem to give an error, just looks like a stop command (C^) is issued in the console without any prodding:

11/03/2022 15:23:12: Placed locations in zone -5,-7  duration 1.497 ms
11/03/2022 15:23:12: Placed locations in zone -5,-5  duration 2.386 ms
11/03/2022 15:23:13: Placed locations in zone -5,-3  duration 13.665 ms
^C11/03/2022 15:26:47: Game - OnApplicationQuit
11/03/2022 15:26:47: Shuting down
11/03/2022 15:26:47: ZNet Shutdown
baconinthemorn commented 2 years ago

Well I found a fix! After more digging into log files I noticed output stating the MONITOR was making several attempts to query via gsquery and eventually restarting the server due to failures:

Nov 04 04:20:04.539 vhserver: MONITOR: INFO: Checking session: CHECKING
Nov 04 04:20:05.549 vhserver: MONITOR: PASS: Checking session: OK
Nov 04 04:20:05.553 vhserver: MONITOR: INFO: gamedig is not installed
Nov 04 04:20:05.558 vhserver: MONITOR: INFO: https://docs.linuxgsm.com/requirements/gamedig
Nov 04 04:20:06.565 vhserver: MONITOR: INFO: Querying port: gsquery: <IP_ADDRESS>:2457 : 1 : QUERYING
Nov 04 04:20:12.635 vhserver: MONITOR: WARN: Querying port: gsquery: <IP_ADDRESS>:2457 : 1: FAIL
Nov 04 04:20:28.698 vhserver: MONITOR: INFO: Querying port: gsquery: <IP_ADDRESS>:2457 : 2 : QUERYING
Nov 04 04:20:34.751 vhserver: MONITOR: WARN: Querying port: gsquery: <IP_ADDRESS>:2457 : 2: FAIL
Nov 04 04:20:50.806 vhserver: MONITOR: INFO: Querying port: gsquery: <IP_ADDRESS>:2457 : 3 : QUERYING
Nov 04 04:20:56.861 vhserver: MONITOR: WARN: Querying port: gsquery: <IP_ADDRESS>:2457 : 3: FAIL
Nov 04 04:21:12.915 vhserver: MONITOR: INFO: Querying port: gsquery: <IP_ADDRESS>:2457 : 4 : QUERYING
Nov 04 04:21:18.985 vhserver: MONITOR: WARN: Querying port: gsquery: <IP_ADDRESS>:2457 : 4: FAIL
Nov 04 04:21:35.041 vhserver: MONITOR: INFO: Querying port: gsquery: <IP_ADDRESS>:2457 : 5 : QUERYING
Nov 04 04:21:41.106 vhserver: MONITOR: WARN: Querying port: gsquery: <IP_ADDRESS>:2457 : 5: FAIL
Nov 04 04:21:42.112 vhserver: MONITOR: WARN: Querying port: gsquery: <IP_ADDRESS>:2457 : 5: FAIL
Nov 04 04:21:42.118 vhserver: MONITOR: INFO: Sending alert: Restarted: vhserver
Nov 04 04:21:43.587 vhserver: STOP: INFO: Graceful: CTRL+c
Nov 04 04:21:50.658 vhserver: STOP: PASS: Graceful: CTRL+c: OK: 5 seconds
Nov 04 04:21:51.571 vhserver: START: INFO: Using anonymous Steam login
Nov 04 04:21:52.326 vhserver: START: INFO: Rotating log files

So I updated my configs to a different query option and I was able to play for 1+ hour uninterrupted last night. Here is the snippet I added to ~/lgsm/config-lgsm/vhserver/vhserver.cfg

## Query mode
# 1: session only
# 2: gamedig (gsquery fallback)
# 3: gamedig
# 4: gsquery
# 5: tcp
querymode="1"  # Set this to 1 instead of "2"
querytype="protocol-valve"

Back in action with the V+ mod enabled. Hope this helps anyone else in a similar situation! Thank you to @Angeal87 for considering options with me.