roydejong / BeatSaberMultiplayerChat

💬 Voice & text chat mod for Beat Saber multiplayer
MIT License
6 stars 3 forks source link

Connection issues with BeatUpServer #2

Closed jabberjabberjabber closed 1 year ago

jabberjabberjabber commented 1 year ago

Compiled with VStudio2022 on WIn 10

Build started... 1>------ Build started: Project: MultiplayerChat, Configuration: Debug Any CPU ------ 1>C:\Users\User\Code\bschat\MultiplayerChat.csproj(193,9,193,9): message BSMT17: Project does not appear to be in a git repository. 1>Product version: 'dev--local' 1>C:\Users\User\Code\bschat\Directory.Build.targets(33,9,33,9): message BSMT17: Project does not appear to be in a git repository. 1>MultiplayerChat -> C:\Users\User\Code\bschat\bin\Debug\net472\MultiplayerChat.dll 1>C:\Users\User\Code\bschat\Directory.Build.targets(98,9): warning : Unable to copy to Plugins folder, 'BeatSaberDir' has not been set in your 'csproj.user' file. 1>Done building project "MultiplayerChat.csproj". ========== Build: 1 succeeded, 0 failed, 0 up-to-date, 0 skipped ========== ========== Build started at 4:28 PM and took 00.819 seconds ==========

Loaded BeatSaber 1.29.1 and attempted to join likrdup.com. Stuck at 'entering lobby'. Attempted to join master.battletrains.org, stuck at 'entering lobby'. Attempted to join beattogether master server. Success.

Also, noticed that when a player joined they briefly got listed in the roster twice.

Log: (username and secrets redacted)

EBUG @ 16:31:06 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ServerDropdown.GetInitValues(idx=1, numberOfElements=4) [DEBUG @ 16:31:07 | MultiplayerCore/PlayerCountPatcher] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Creating server form with player clamp between '2' and '254' [DEBUG @ 16:31:07 | IPA] {IPA.Logging.Printers.GZFilePrinter+<CompressOldLog>d__9::MoveNext()} Compressing log file C:\Program Files (x86)\Steam\steamapps\common\Beat Saber\Logs\MultiplayerCore\PlayerCountPatcher\2023.05.02.07.39.07.log [DEBUG @ 16:31:07 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:07 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:07 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:07 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:09 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Performing handshake... [DEBUG @ 16:31:09 | IPA] {IPA.Logging.Printers.GZFilePrinter+<CompressOldLog>d__9::MoveNext()} Compressing log file C:\Program Files (x86)\Steam\steamapps\common\Beat Saber\Logs\ServerBrowser\JoiningLobbyExtender\2023.05.02.07.39.13.log [DEBUG @ 16:31:10 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} HandleConnectToServerSuccess(enableCustomLevels=True, maxPlayerCount=6) [DEBUG @ 16:31:10 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Connecting to game... [DEBUG @ 16:31:10 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() [DEBUG @ 16:31:10 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() end [INFO @ 16:31:10 | ServerBrowser/BssbDataCollector] Game will connect to GameLift session (playerSessionId=pslot$0,000, hostName=38.45.65.246, port=8106, gameSessionId=beatupserver:31251ba7, code=A, maxPlayerCount=6, discoveryPolicy=Public, gameplayServerMode=Managed, songSelectionMode=OwnerPicks) [DEBUG @ 16:31:10 | IPA] {IPA.Logging.Printers.GZFilePrinter+<CompressOldLog>d__9::MoveNext()} Compressing log file C:\Program Files (x86)\Steam\steamapps\common\Beat Saber\Logs\ServerBrowser\BssbDataCollector\2023.05.02.07.39.14.log [INFO @ 16:31:10 | BeatUpClient] Overriding window size - 256 [DEBUG @ 16:31:10 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ReliableChannel_ctor(default) [DEBUG @ 16:31:10 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ConnectInfo from [ConnectedPlayer (beatupserver:31251ba7) isMe:False isConnectionOwner:True] [DEBUG @ 16:31:10 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Entering lobby... [INFO @ 16:31:10 | ServerBrowser/BssbDataCollector] Multiplayer session connected (syncTime=0.3822803) [INFO @ 16:31:10 | ServerBrowser/BssbDataCollector] Player connected (sortIndex=-1, userId=beatupserver:31251ba7, userName=, isMe=False, isConnectionOwner=True, currentLatency=0.034) [INFO @ 16:31:10 | ServerBrowser/BssbDataCollector] Player connected (sortIndex=0, userId=, userName=, isMe=True, isConnectionOwner=False, currentLatency=0) [DEBUG @ 16:31:10 | ServerBrowser/BssbDataCollector] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Detected a BeatUpServer host [DEBUG @ 16:31:10 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} MultiplayerChat v0.1.0.0 <color=#95a5a6>(dev--local)</color> [DEBUG @ 16:31:10 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Connected to Dedicated Server [DEBUG @ 16:31:10 | MultiplayerCore/MpPacketSerializer] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Registered packet 'MultiplayerCore.Beatmaps.Packets.MpBeatmapPacket' with id 'MpBeatmapPacket'. [DEBUG @ 16:31:10 | ServerBrowser/BssbMenuDataCollector] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Lobby state changed to: LobbySetup [DEBUG @ 16:31:10 | IPA] {IPA.Logging.Printers.GZFilePrinter+<CompressOldLog>d__9::MoveNext()} Compressing log file C:\Program Files (x86)\Steam\steamapps\common\Beat Saber\Logs\ServerBrowser\BssbMenuDataCollector\2023.05.02.07.39.14.log [INFO @ 16:31:34 | ServerBrowser/BssbDataCollector] Multiplayer session disconnected (reason=UserInitiated) [DEBUG @ 16:31:34 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ServerDropdown.GetInitValues(idx=1, numberOfElements=4) [DEBUG @ 16:31:36 | MultiplayerCore/PlayerCountPatcher] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Creating server form with player clamp between '2' and '254' [DEBUG @ 16:31:36 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:36 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:36 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:38 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Performing handshake... [DEBUG @ 16:31:38 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} HandleConnectToServerSuccess(enableCustomLevels=True, maxPlayerCount=6) [DEBUG @ 16:31:38 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Connecting to game... [DEBUG @ 16:31:38 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() [DEBUG @ 16:31:38 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() end [INFO @ 16:31:38 | ServerBrowser/BssbDataCollector] Game will connect to GameLift session (playerSessionId=pslot$0,000, hostName=38.45.65.246, port=8106, gameSessionId=beatupserver:31251ba7, secret=, code=A, maxPlayerCount=6, discoveryPolicy=Public, gameplayServerMode=Managed, songSelectionMode=OwnerPicks) [INFO @ 16:31:38 | BeatUpClient] Overriding window size - 256 [DEBUG @ 16:31:38 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ReliableChannel_ctor(default) [DEBUG @ 16:31:38 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ConnectInfo from [ConnectedPlayer (beatupserver:31251ba7) isMe:False isConnectionOwner:True] [DEBUG @ 16:31:38 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Entering lobby... [INFO @ 16:31:38 | ServerBrowser/BssbDataCollector] Multiplayer session connected (syncTime=0.2524891) [INFO @ 16:31:38 | ServerBrowser/BssbDataCollector] Player connected (sortIndex=-1, userId=beatupserver:31251ba7, userName=, isMe=False, isConnectionOwner=True, currentLatency=0.032) [INFO @ 16:31:38 | ServerBrowser/BssbDataCollector] Player connected (sortIndex=0, userId=, userName=, isMe=True, isConnectionOwner=False, currentLatency=0) [DEBUG @ 16:31:38 | ServerBrowser/BssbDataCollector] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Detected a BeatUpServer host [DEBUG @ 16:31:38 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} MultiplayerChat v0.1.0.0 <color=#95a5a6>(dev--local)</color> [DEBUG @ 16:31:38 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Connected to Dedicated Server [DEBUG @ 16:31:38 | MultiplayerCore/MpPacketSerializer] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Registered packet 'MultiplayerCore.Beatmaps.Packets.MpBeatmapPacket' with id 'MpBeatmapPacket'. [INFO @ 16:31:44 | ServerBrowser/BssbDataCollector] Multiplayer session disconnected (reason=UserInitiated) [DEBUG @ 16:31:44 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ServerDropdown.GetInitValues(idx=1, numberOfElements=4) [DEBUG @ 16:31:46 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ServerDropdown.GetInitValues(idx=2, numberOfElements=4) [DEBUG @ 16:31:48 | MultiplayerCore/PlayerCountPatcher] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Creating server form with player clamp between '2' and '254' [DEBUG @ 16:31:48 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:48 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:48 | IPA/Config] {IPA.Config.Stores.GeneratedStoreImpl+Impl::WriteTo(IPA.Config.ConfigProvider)} Generated impl WriteTo BeatUpClient_Config<Generated> [DEBUG @ 16:31:49 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Performing handshake... [DEBUG @ 16:31:50 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} HandleConnectToServerSuccess(enableCustomLevels=True, maxPlayerCount=6) [DEBUG @ 16:31:50 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Connecting to game... [DEBUG @ 16:31:50 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() [DEBUG @ 16:31:50 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() end [INFO @ 16:31:50 | ServerBrowser/BssbDataCollector] Game will connect to GameLift session (playerSessionId=pslot$0,000, hostName=master.battletrains.org, port=8106, gameSessionId=beatupserver:31251ba7, secret=, code=A, maxPlayerCount=6, discoveryPolicy=Public, gameplayServerMode=Managed, songSelectionMode=OwnerPicks) [INFO @ 16:31:50 | BeatUpClient] Overriding window size - 256 [DEBUG @ 16:31:50 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ReliableChannel_ctor(default) [DEBUG @ 16:31:50 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ConnectInfo from [ConnectedPlayer (beatupserver:31251ba7) isMe:False isConnectionOwner:True] [DEBUG @ 16:31:50 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Entering lobby... [INFO @ 16:31:50 | ServerBrowser/BssbDataCollector] Multiplayer session connected (syncTime=0.6403313) [INFO @ 16:31:50 | ServerBrowser/BssbDataCollector] Player connected (, isMe=False, isConnectionOwner=True, currentLatency=0.09) [INFO @ 16:31:50 | ServerBrowser/BssbDataCollector] Player connected (, isMe=True, isConnectionOwner=False, currentLatency=0) [DEBUG @ 16:31:50 | ServerBrowser/BssbDataCollector] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Detected a BeatUpServer host [DEBUG @ 16:31:50 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} MultiplayerChat v0.1.0.0 <color=#95a5a6>(dev--local)</color> [DEBUG @ 16:31:50 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Connected to Dedicated Server [DEBUG @ 16:31:50 | MultiplayerCore/MpPacketSerializer] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Registered packet 'MultiplayerCore.Beatmaps.Packets.MpBeatmapPacket' with id 'MpBeatmapPacket'. [INFO @ 16:31:56 | ServerBrowser/BssbDataCollector] Multiplayer session disconnected (reason=UserInitiated) [DEBUG @ 16:31:56 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ServerDropdown.GetInitValues(idx=2, numberOfElements=4) [DEBUG @ 16:31:59 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ServerDropdown.GetInitValues(idx=3, numberOfElements=4) [DEBUG @ 16:32:00 | MultiplayerCore/PlayerCountPatcher] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Creating server form with player clamp between '2' and '254' [DEBUG @ 16:32:04 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Performing handshake... [DEBUG @ 16:32:04 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} HandleConnectToServerSuccess(enableCustomLevels=True, maxPlayerCount=6) [DEBUG @ 16:32:04 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Connecting to game... [DEBUG @ 16:32:04 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() [DEBUG @ 16:32:04 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} LiteNetLibConnectionManager_GetConnectionMessage() end [INFO @ 16:32:04 | ServerBrowser/BssbDataCollector] Game will connect to GameLift session (, code=34FFE, maxPlayerCount=6, discoveryPolicy=Public, gameplayServerMode=Managed, songSelectionMode=Vote) [DEBUG @ 16:32:04 | BeatUpClient] {BeatUpClient_BSIPA+LogWrapper::Debug(System.String)} ReliableChannel_ctor(default) [DEBUG @ 16:32:04 | ServerBrowser/JoiningLobbyExtender] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Extended join status: Entering lobby... [INFO @ 16:32:04 | ServerBrowser/BssbDataCollector] Multiplayer session connected (syncTime=0.3245354) [INFO @ 16:32:04 | ServerBrowser/BssbDataCollector] Player connected (sortIndex=-1, userName=, isMe=False, isConnectionOwner=True, currentLatency=0) [INFO @ 16:32:04 | ServerBrowser/BssbDataCollector] Player connected ( isMe=True, isConnectionOwner=False, currentLatency=0) [DEBUG @ 16:32:04 | ServerBrowser/BssbDataCollector] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Detected a BeatTogether host [DEBUG @ 16:32:04 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} MultiplayerChat v0.1.0.0 <color=#95a5a6>(dev--local)</color> [DEBUG @ 16:32:04 | MultiplayerChat/ChatManager] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Connected to Dedicated Server [DEBUG @ 16:32:04 | MultiplayerCore/MpPacketSerializer] {SiraUtil.Logging.SiraLog::Debug(System.Object)} Registered packet 'MultiplayerCore.Beatmaps.Packets.MpBeatmapPacket' with id 'MpBeatmapPacket'. [INFO @ 16:32:04 | ServerBrowser/BssbDataCollector] Party leader changed to (userId=, userName=, isMe=True) [INFO @ 16:32:04 | ServerBrowser/BssbServerAnnouncer] Starting announcing (late/host migration)

Hit me up on discord if you need more logs.

rcelyte commented 1 year ago

This seems fairly inconsistent (and likely ping dependent). One of 3 things happens:

Edit: The fade scenario appears to be a Beat Games Moment™ with LobbyGameStateController.isDisconnected not being cleared properly after a failed connection. It isn't the fault of this mod or the server.

rcelyte commented 1 year ago

Seems like _sessionManager.Send(_localCapabilities); is the offending line; will investigate further...

rcelyte commented 1 year ago

@roydejong btw _sessionManager.playerDisconnectedEvent += HandleSessionPlayerDisconnected; is missing the matching -= in ChatManager.Dispose()

rcelyte commented 1 year ago

Oh whoops, looks like the issue was on my end. This line being a return instead of a continue caused the processing loop to exit early when it hit a message it didn't understand, dropping subsequent messages in the same packet x_x

roydejong commented 1 year ago

Thanks for the info! Very good to hear we have a solution. 👍