From fc598cf8781fcc20c130ab223b395290c1626779 Mon Sep 17 00:00:00 2001 From: past-due <30942300+past-due@users.noreply.github.com> Date: Sun, 27 Oct 2024 17:01:10 -0400 Subject: [PATCH 1/3] joiningscreen: Display and log connection state on timeout --- src/screens/joiningscreen.cpp | 75 ++++++++++++++++++++++++++++++++--- 1 file changed, 70 insertions(+), 5 deletions(-) diff --git a/src/screens/joiningscreen.cpp b/src/screens/joiningscreen.cpp index d249fe76c90..c3ad785edb4 100644 --- a/src/screens/joiningscreen.cpp +++ b/src/screens/joiningscreen.cpp @@ -419,7 +419,7 @@ int32_t WzJoiningStatusForm::calculateNeededHeight(bool withDetailsParagraph) } else { - result += statusDetails->height(); + result += statusDetails->idealHeight(); } result += InternalPadding; if (passwordPrompt && passwordPrompt->visible()) @@ -521,7 +521,7 @@ void WzJoiningStatusForm::recalcLayout() int statusDetailsX0 = InternalPadding; int statusDetailsWidth = usableWidth; - statusDetails->setGeometry(statusDetailsX0, lastLineY1 + DetailsLabelParagraphPadding, statusDetailsWidth, statusDetails->height()); + statusDetails->setGeometry(statusDetailsX0, lastLineY1 + DetailsLabelParagraphPadding, statusDetailsWidth, statusDetails->idealHeight()); int paragraphHeight = usableHeight - DetailsLabelParagraphPadding; scrollableParagraphContainer->setGeometry(InternalPadding, lastLineY1 + DetailsLabelParagraphPadding, usableWidth, paragraphHeight); @@ -546,7 +546,7 @@ void WzJoiningStatusForm::displayStatus(const WzString &statusDescription) } scrollableParagraphContainer->hide(); - statusDetails->setString(statusDescription); + statusDetails->setFormattedString(statusDescription, std::numeric_limits::max(), font_regular); statusDetails->show(); } @@ -780,6 +780,10 @@ class WzJoiningGameScreen_HandlerRoot : public W_CLICKFORM }; JoiningState currentJoiningState = JoiningState::AwaitingConnection; + const char* to_string(JoiningState s); + const char* to_display_str(JoiningState s); + const char* to_localized_state_fail_desc(JoiningState s); + // state when handling initial connection join uint32_t startTime = 0; Socket* client_transient_socket = nullptr; @@ -956,12 +960,73 @@ void WzJoiningGameScreen_HandlerRoot::updateJoiningStatus(const WzString& status joiningProgressForm->displayProgressStatus(statusDescription); } +const char* WzJoiningGameScreen_HandlerRoot::to_string(JoiningState s) +{ + switch (s) { + case JoiningState::NeedsPassword: return "NeedsPassword"; + case JoiningState::AwaitingConnection: return "AwaitingConnection"; + case JoiningState::AwaitingInitialNetcodeHandshakeAck: return "AwaitingInitialNetcodeHandshakeAck"; + case JoiningState::ProcessingJoinMessages: return "ProcessingJoinMessages"; + case JoiningState::Failure: return "Failure"; + case JoiningState::SuccessPendingClose: return "SuccessPendingClose"; + case JoiningState::Success: return "Success"; + } + return ""; // silence compiler warning +} + +const char* WzJoiningGameScreen_HandlerRoot::to_display_str(JoiningState s) +{ + switch (s) { + case JoiningState::NeedsPassword: return "NeedsPassword"; + case JoiningState::AwaitingConnection: return "PendingConnect"; + case JoiningState::AwaitingInitialNetcodeHandshakeAck: return "NetcodeHandshake"; + case JoiningState::ProcessingJoinMessages: return "ProcessingJoin"; + case JoiningState::Failure: return "Failure"; + case JoiningState::SuccessPendingClose: return "SuccessPendingClose"; + case JoiningState::Success: return "Success"; + } + return ""; // silence compiler warning +} + +const char* WzJoiningGameScreen_HandlerRoot::to_localized_state_fail_desc(JoiningState s) +{ + switch (s) { + case JoiningState::NeedsPassword: + return _("Waiting for correct join password"); + case JoiningState::AwaitingConnection: + return _("Attempting to connect"); + case JoiningState::AwaitingInitialNetcodeHandshakeAck: + return _("Establishing connection handshake"); + case JoiningState::ProcessingJoinMessages: + return _("Coordinating join with host"); + case JoiningState::Failure: + return _("Join attempt failed"); + case JoiningState::SuccessPendingClose: + case JoiningState::Success: + return ""; + } + return ""; // silence compiler warning +} + void WzJoiningGameScreen_HandlerRoot::handleJoinTimeoutError() { + debug(LOG_INFO, "Failed to join with timeout, state: %s", to_string(currentJoiningState)); + + WzString timeoutErrorDetails = _("Host did not respond before timeout"); + timeoutErrorDetails += "\n"; + WzString localizedJoinStateDesc = to_localized_state_fail_desc(currentJoiningState); + if (!localizedJoinStateDesc.isEmpty()) + { + timeoutErrorDetails += WzString::fromUtf8(astringf(_("Failed at: [%s] - %s"), to_display_str(currentJoiningState), localizedJoinStateDesc.toUtf8().c_str())); + } + else + { + timeoutErrorDetails += WzString::fromUtf8(astringf(_("Failed at: [%s]"), to_display_str(currentJoiningState))); + } + currentJoiningState = JoiningState::Failure; - debug(LOG_INFO, "Failed to join with timeout"); - joiningProgressForm->displayUnableToJoinError(_("Host did not respond before timeout")); + joiningProgressForm->displayUnableToJoinError(timeoutErrorDetails); joiningProgressForm->callCalcLayout(); if (onFailureFunc) From a3e40e527bd055757c1743171a5608423d145daa Mon Sep 17 00:00:00 2001 From: past-due <30942300+past-due@users.noreply.github.com> Date: Sun, 27 Oct 2024 18:43:20 -0400 Subject: [PATCH 2/3] Add host auto kick on sustained desync Defaults to kicking if a player remains in desync status for 10 seconds --- lib/netplay/netplay.cpp | 1 + src/configuration.cpp | 2 + src/multiint.cpp | 1 + src/multijoin.cpp | 3 ++ src/multiopt.cpp | 1 + src/multiplay.cpp | 104 +++++++++++++++++++++++++++++++++++++--- src/multiplay.h | 2 + src/warzoneconfig.cpp | 16 +++++++ src/warzoneconfig.h | 2 + 9 files changed, 126 insertions(+), 6 deletions(-) diff --git a/lib/netplay/netplay.cpp b/lib/netplay/netplay.cpp index fa2cd4a5432..a910db4e40d 100644 --- a/lib/netplay/netplay.cpp +++ b/lib/netplay/netplay.cpp @@ -1930,6 +1930,7 @@ static bool swapPlayerIndexes(uint32_t playerIndexA, uint32_t playerIndexB) // Swap certain ingame player-associated entries std::swap(ingame.PingTimes[playerIndexA], ingame.PingTimes[playerIndexB]); std::swap(ingame.LagCounter[playerIndexA], ingame.LagCounter[playerIndexB]); + std::swap(ingame.DesyncCounter[playerIndexA], ingame.DesyncCounter[playerIndexB]); std::swap(ingame.VerifiedIdentity[playerIndexA], ingame.VerifiedIdentity[playerIndexB]); std::swap(ingame.JoiningInProgress[playerIndexA], ingame.JoiningInProgress[playerIndexB]); std::swap(ingame.PendingDisconnect[playerIndexA], ingame.PendingDisconnect[playerIndexB]); diff --git a/src/configuration.cpp b/src/configuration.cpp index 9e80090bbff..8b0d1176eab 100644 --- a/src/configuration.cpp +++ b/src/configuration.cpp @@ -582,6 +582,7 @@ bool loadConfig() pie_EnableFog(false); } war_setAutoLagKickSeconds(iniGetInteger("hostAutoLagKickSeconds", war_getAutoLagKickSeconds()).value()); + war_setAutoDesyncKickSeconds(iniGetInteger("hostAutoDesyncKickSeconds", war_getAutoDesyncKickSeconds()).value()); war_setDisableReplayRecording(iniGetBool("disableReplayRecord", war_getDisableReplayRecording()).value()); war_setMaxReplaysSaved(iniGetInteger("maxReplaysSaved", war_getMaxReplaysSaved()).value()); war_setOldLogsLimit(iniGetInteger("oldLogsLimit", war_getOldLogsLimit()).value()); @@ -773,6 +774,7 @@ bool saveConfig() iniSetBool("autosaveEnabled", autosaveEnabled); iniSetBool("fog", pie_GetFogEnabled()); iniSetInteger("hostAutoLagKickSeconds", war_getAutoLagKickSeconds()); + iniSetInteger("hostAutoDesyncKickSeconds", war_getAutoDesyncKickSeconds()); iniSetBool("disableReplayRecord", war_getDisableReplayRecording()); iniSetInteger("maxReplaysSaved", war_getMaxReplaysSaved()); iniSetInteger("oldLogsLimit", war_getOldLogsLimit()); diff --git a/src/multiint.cpp b/src/multiint.cpp index 86258b9b6ea..1335d5c84da 100644 --- a/src/multiint.cpp +++ b/src/multiint.cpp @@ -6198,6 +6198,7 @@ bool WzMultiplayerOptionsTitleUI::startHost() ingame.PingTimes[i] = 0; ingame.VerifiedIdentity[i] = false; ingame.LagCounter[i] = 0; + ingame.DesyncCounter[i] = 0; ingame.lastSentPlayerDataCheck2[i].reset(); ingame.muteChat[i] = false; } diff --git a/src/multijoin.cpp b/src/multijoin.cpp index 1d011c64a27..cabcad22a17 100644 --- a/src/multijoin.cpp +++ b/src/multijoin.cpp @@ -99,6 +99,7 @@ void clearPlayer(UDWORD player, bool quietly) debug(LOG_NET, "R.I.P. %s (%u). quietly is %s", getPlayerName(player), player, quietly ? "true" : "false"); ingame.LagCounter[player] = 0; + ingame.DesyncCounter[player] = 0; ingame.JoiningInProgress[player] = false; // if they never joined, reset the flag ingame.DataIntegrity[player] = false; ingame.hostChatPermissions[player] = false; @@ -332,6 +333,7 @@ void handlePlayerLeftInGame(UDWORD player) debug(LOG_NET, "R.I.P. %s (%u).", getPlayerName(player), player); ingame.LagCounter[player] = 0; + ingame.DesyncCounter[player] = 0; ingame.JoiningInProgress[player] = false; // if they never joined, reset the flag ingame.PendingDisconnect[player] = false; ingame.DataIntegrity[player] = false; @@ -671,6 +673,7 @@ void setupNewPlayer(UDWORD player) ingame.PingTimes[player] = 0; // Reset ping time ingame.LagCounter[player] = 0; + ingame.DesyncCounter[player] = 0; ingame.VerifiedIdentity[player] = false; ingame.JoiningInProgress[player] = true; // Note that player is now joining ingame.PendingDisconnect[player] = false; diff --git a/src/multiopt.cpp b/src/multiopt.cpp index 960471921f3..023f47d4bd8 100644 --- a/src/multiopt.cpp +++ b/src/multiopt.cpp @@ -724,6 +724,7 @@ bool multiGameShutdown() ingame.startTime = std::chrono::steady_clock::time_point(); ingame.endTime = nullopt; ingame.lastLagCheck = std::chrono::steady_clock::time_point(); + ingame.lastDesyncCheck = std::chrono::steady_clock::time_point(); ingame.lastPlayerDataCheck2 = std::chrono::steady_clock::time_point(); NetPlay.isHost = false; bMultiPlayer = false; // Back to single player mode diff --git a/src/multiplay.cpp b/src/multiplay.cpp index 932937c6bb9..6828647a8ee 100644 --- a/src/multiplay.cpp +++ b/src/multiplay.cpp @@ -116,13 +116,13 @@ static bool sendDataCheck2(); void startMultiplayerGame(); // //////////////////////////////////////////////////////////////////////////// -// Auto Lag Kick Handling +// Auto Bad Connection Kick Handling #define LAG_INITIAL_LOAD_GRACEPERIOD 60 #define LAG_CHECK_INTERVAL 1000 const std::chrono::milliseconds LagCheckInterval(LAG_CHECK_INTERVAL); -void autoLagKickRoutine() +void autoLagKickRoutine(std::chrono::steady_clock::time_point now) { if (!bMultiPlayer || !NetPlay.bComms || !NetPlay.isHost) { @@ -135,7 +135,6 @@ void autoLagKickRoutine() return; } - const std::chrono::steady_clock::time_point now = std::chrono::steady_clock::now(); if (std::chrono::duration_cast(now - ingame.lastLagCheck) < LagCheckInterval) { return; @@ -225,12 +224,103 @@ void autoLagKickRoutine() ingame.LagCounter[i] = 0; } else if (ingame.LagCounter[i] >= (LagAutoKickSeconds - 3)) { - std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") in %u seconds.", i, getPlayerName(i), (LagAutoKickSeconds - ingame.LagCounter[i])); + std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") in %u seconds. (lag)", i, getPlayerName(i), (LagAutoKickSeconds - ingame.LagCounter[i])); debug(LOG_INFO, "%s", msg.c_str()); sendInGameSystemMessage(msg.c_str()); } else if (ingame.LagCounter[i] % 15 == 0) { // every 15 seconds - std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") in %u seconds.", i, getPlayerName(i), (LagAutoKickSeconds - ingame.LagCounter[i])); + std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") in %u seconds. (lag)", i, getPlayerName(i), (LagAutoKickSeconds - ingame.LagCounter[i])); + debug(LOG_INFO, "%s", msg.c_str()); + sendInGameSystemMessage(msg.c_str()); + } + } +} + +void autoLagKickRoutine() +{ + if (!bMultiPlayer || !NetPlay.bComms || !NetPlay.isHost) + { + return; + } + + const std::chrono::steady_clock::time_point now = std::chrono::steady_clock::now(); + autoLagKickRoutine(now); +} + +#define DESYNC_CHECK_INTERVAL 1000 +const std::chrono::milliseconds DesyncCheckInterval(DESYNC_CHECK_INTERVAL); + +void autoDesyncKickRoutine(std::chrono::steady_clock::time_point now) +{ + if (!bMultiPlayer || !NetPlay.bComms || !NetPlay.isHost) + { + return; + } + + int DesyncAutoKickSeconds = war_getAutoDesyncKickSeconds(); + if (DesyncAutoKickSeconds <= 0) + { + return; + } + + if (std::chrono::duration_cast(now - ingame.lastDesyncCheck) < DesyncCheckInterval) + { + return; + } + + if (ingame.endTime.has_value()) + { + // game ended - skip desync check / kick + return; + } + + ingame.lastDesyncCheck = now; + uint32_t playerCheckLimit = MAX_PLAYERS; + for (uint32_t i = 0; i < playerCheckLimit; ++i) + { + if (!isHumanPlayer(i)) + { + continue; + } + if (i == NetPlay.hostPlayer) + { + continue; + } + if (i > MAX_PLAYERS && !gtimeShouldWaitForPlayer(i)) + { + continue; + } + + bool isDesynced = NETcheckPlayerConnectionStatus(CONNECTIONSTATUS_DESYNC, i); + + if (!isDesynced) + { + ingame.DesyncCounter[i] = 0; + continue; + } + + if (ingame.PendingDisconnect[i]) + { + // player already technically left, but we're still in the "pre-game" phase so the GAME_PLAYER_LEFT hasn't been processed yet + continue; + } + + ingame.DesyncCounter[i]++; + if (ingame.DesyncCounter[i] >= DesyncAutoKickSeconds) { + std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") because of desync. (Timeout: %u seconds)", i, getPlayerName(i), DesyncAutoKickSeconds); + debug(LOG_INFO, "%s", msg.c_str()); + sendInGameSystemMessage(msg.c_str()); + wz_command_interface_output("WZEVENT: desync-kick: %u %s\n", i, NetPlay.players[i].IPtextAddress); + kickPlayer(i, "Your game simulation deviated too far from the host - desync.", ERROR_CONNECTION, false); + ingame.DesyncCounter[i] = 0; + } + else if (ingame.DesyncCounter[i] >= (DesyncAutoKickSeconds - 3)) { + std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") in %u seconds. (desync)", i, getPlayerName(i), (DesyncAutoKickSeconds - ingame.DesyncCounter[i])); + debug(LOG_INFO, "%s", msg.c_str()); + sendInGameSystemMessage(msg.c_str()); + } + else if (ingame.DesyncCounter[i] % 2 == 0) { // every 2 seconds + std::string msg = astringf("Auto-kicking player %" PRIu32 " (\"%s\") in %u seconds. (desync)", i, getPlayerName(i), (DesyncAutoKickSeconds - ingame.DesyncCounter[i])); debug(LOG_INFO, "%s", msg.c_str()); sendInGameSystemMessage(msg.c_str()); } @@ -414,7 +504,9 @@ bool multiPlayerLoop() if (NetPlay.isHost) { - autoLagKickRoutine(); + const std::chrono::steady_clock::time_point now = std::chrono::steady_clock::now(); + autoLagKickRoutine(now); + autoDesyncKickRoutine(now); processPendingKickVotes(); } diff --git a/src/multiplay.h b/src/multiplay.h index efcec425ded..e359cb062cf 100644 --- a/src/multiplay.h +++ b/src/multiplay.h @@ -107,6 +107,7 @@ struct MULTIPLAYERINGAME { UDWORD PingTimes[MAX_CONNECTED_PLAYERS]; // store for pings. int LagCounter[MAX_CONNECTED_PLAYERS]; + int DesyncCounter[MAX_CONNECTED_PLAYERS]; bool VerifiedIdentity[MAX_CONNECTED_PLAYERS]; // if the multistats identity has been verified. bool localOptionsReceived; // used to show if we have game options yet.. bool localJoiningInProgress; // used before we know our player number. @@ -120,6 +121,7 @@ struct MULTIPLAYERINGAME std::chrono::steady_clock::time_point startTime; optional endTime; std::chrono::steady_clock::time_point lastLagCheck; + std::chrono::steady_clock::time_point lastDesyncCheck; optional lastSentPlayerDataCheck2[MAX_CONNECTED_PLAYERS] = {}; std::chrono::steady_clock::time_point lastPlayerDataCheck2; bool muteChat[MAX_CONNECTED_PLAYERS] = {false}; // the local client-set mute status for this player diff --git a/src/warzoneconfig.cpp b/src/warzoneconfig.cpp index 779cae71373..de95984cae8 100644 --- a/src/warzoneconfig.cpp +++ b/src/warzoneconfig.cpp @@ -74,6 +74,7 @@ struct WARZONE_GLOBALS JS_BACKEND jsBackend = (JS_BACKEND)0; bool autoAdjustDisplayScale = true; int autoLagKickSeconds = 60; + int autoDesyncKickSeconds = 10; bool disableReplayRecording = false; int maxReplaysSaved = MAX_REPLAY_FILES; int oldLogsLimit = MAX_OLD_LOGS; @@ -486,6 +487,21 @@ void war_setAutoLagKickSeconds(int seconds) warGlobs.autoLagKickSeconds = seconds; } +int war_getAutoDesyncKickSeconds() +{ + return warGlobs.autoDesyncKickSeconds; +} + +void war_setAutoDesyncKickSeconds(int seconds) +{ + seconds = std::max(seconds, 0); + if (seconds > 0) + { + seconds = std::max(seconds, 10); + } + warGlobs.autoDesyncKickSeconds = seconds; +} + bool war_getDisableReplayRecording() { return warGlobs.disableReplayRecording; diff --git a/src/warzoneconfig.h b/src/warzoneconfig.h index 91b00d5cff7..6ebb79189c7 100644 --- a/src/warzoneconfig.h +++ b/src/warzoneconfig.h @@ -132,6 +132,8 @@ bool war_getAutoAdjustDisplayScale(); void war_setAutoAdjustDisplayScale(bool autoAdjustDisplayScale); int war_getAutoLagKickSeconds(); void war_setAutoLagKickSeconds(int seconds); +int war_getAutoDesyncKickSeconds(); +void war_setAutoDesyncKickSeconds(int seconds); bool war_getDisableReplayRecording(); void war_setDisableReplayRecording(bool disable); int war_getMaxReplaysSaved(); From 353b3d87a4a122ee94f46000fa08ac916fdcfaff Mon Sep 17 00:00:00 2001 From: past-due <30942300+past-due@users.noreply.github.com> Date: Sun, 27 Oct 2024 19:50:02 -0400 Subject: [PATCH 3/3] Fix: Only play "Player is exiting" audio when player slot drops (ignore spectators) --- src/multijoin.cpp | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/multijoin.cpp b/src/multijoin.cpp index cabcad22a17..8ee450cd032 100644 --- a/src/multijoin.cpp +++ b/src/multijoin.cpp @@ -517,7 +517,10 @@ bool MultiPlayerLeave(UDWORD playerIndex) if (widgGetFromID(psWScreen, IDRET_FORM)) { - audio_QueueTrack(ID_CLAN_EXIT); + if (playerIndex < MAX_PLAYERS) // only play audio when *player* slots drop (ignore spectator slots) + { + audio_QueueTrack(ID_CLAN_EXIT); + } } // fire script callback to reassign skirmish players.