From c9be47ced0a6ef3a572de578f8202d09a2f44f29 Mon Sep 17 00:00:00 2001 From: Tim Leonard Date: Sun, 17 Mar 2024 13:53:52 +0000 Subject: [PATCH] Ease up on some of the reliable-udp settings. Fix up hearbeats on client connections (for the client emulator). Added quiet logging option. --- Source/Server/Client/Client.cpp | 25 +++++++--------- Source/Server/Config/RuntimeConfig.cpp | 2 ++ Source/Server/Config/RuntimeConfig.h | 3 ++ Source/Server/Server/Server.cpp | 8 ++++- .../Streams/Frpg2ReliableUdpPacketStream.cpp | 21 +++++++++++++- .../Streams/Frpg2ReliableUdpPacketStream.h | 13 ++++++--- .../Server/Streams/Frpg2UdpPacketStream.cpp | 1 + .../Server/Streams/Frpg2UdpPacketStream.h | 2 ++ Source/Shared/Core/Utils/Logging.cpp | 13 ++++++++- Source/Shared/Core/Utils/Logging.h | 29 ++++++++++--------- 10 files changed, 83 insertions(+), 34 deletions(-) diff --git a/Source/Server/Client/Client.cpp b/Source/Server/Client/Client.cpp index 5e1a4c6e..dee26b6f 100644 --- a/Source/Server/Client/Client.cpp +++ b/Source/Server/Client/Client.cpp @@ -444,6 +444,9 @@ void Client::Handle_AuthServer_GetServerInfo() GameServerIP = GameInfo.game_server_ip; GameServerPort = GameInfo.game_port; + AuthServerConnection->Disconnect(); + AuthServerConnection = nullptr; + ChangeState(ClientState::GameServer_Connect); //LogS(GetName().c_str(), "Recieved game server info: %s:%i (auth token: 0x%016llx)", GameInfo.game_server_ip, GameInfo.game_port, GameInfo.auth_token); @@ -684,8 +687,7 @@ void Client::Handle_GameServer_Idle() Params->set_weapon_level(1); Params->set_unknown_id_15(""); - //DS3_Frpg2RequestMessage::RequestGetSignListResponse Response; - //SendAndAwaitWaitForReply(&Request, &Response); + GameServerMessageStream->Send(&Request, nullptr); break; } @@ -701,8 +703,7 @@ void Client::Handle_GameServer_Idle() Domain->set_max_type_1(20); Domain->set_max_type_2(20); - //DS3_Frpg2RequestMessage::RequestGetBloodMessageListResponse Response; - //SendAndAwaitWaitForReply(&Request, &Response); + GameServerMessageStream->Send(&Request, nullptr); break; } @@ -714,8 +715,7 @@ void Client::Handle_GameServer_Idle() Request.set_online_area_id(1000); Request.set_data(ghost_data.data(), ghost_data.size()); - //DS3_Frpg2RequestMessage::RequestCreateGhostDataResponse Response; - //SendAndAwaitWaitForReply(&Request, &Response); + GameServerMessageStream->Send(&Request, nullptr); break; } @@ -728,10 +728,9 @@ void Client::Handle_GameServer_Idle() DS3_Frpg2RequestMessage::DomainLimitData* Domain = Request.add_search_areas(); Domain->set_online_area_id(30004); - Domain->set_max_items(32); - - //DS3_Frpg2RequestMessage::RequestGetBloodstainListResponse Response; - //SendAndAwaitWaitForReply(&Request, &Response); + Domain->set_max_items(32); + + GameServerMessageStream->Send(&Request, nullptr); break; } @@ -744,8 +743,7 @@ void Client::Handle_GameServer_Idle() Request.set_ghost_data(ghost_data.data(), ghost_data.size()); Request.set_data(ghost_data.data(), ghost_data.size()); - //DS3_Frpg2RequestMessage::EmptyResponse Response; - //SendAndAwaitWaitForReply(&Request, &Response); + GameServerMessageStream->Send(&Request, nullptr); break; } @@ -774,8 +772,7 @@ void Client::Handle_GameServer_Idle() Params->set_weapon_level(1); Params->set_unknown_id_15(""); - //DS3_Frpg2RequestMessage::RequestCreateSignResponse Response; - //SendAndAwaitWaitForReply(&Request, &Response); + GameServerMessageStream->Send(&Request, nullptr); break; } diff --git a/Source/Server/Config/RuntimeConfig.cpp b/Source/Server/Config/RuntimeConfig.cpp index 79cc18d9..9ae54976 100644 --- a/Source/Server/Config/RuntimeConfig.cpp +++ b/Source/Server/Config/RuntimeConfig.cpp @@ -274,6 +274,8 @@ bool RuntimeConfig::Serialize(nlohmann::json& Json, bool Loading) SERIALIZE_VAR(ServerPrivateHostname); SERIALIZE_VAR(GameType); + SERIALIZE_VAR(QuietLogging); + SERIALIZE_VAR(MasterServerIp); SERIALIZE_VAR(MasterServerPort); SERIALIZE_VAR(Advertise); diff --git a/Source/Server/Config/RuntimeConfig.h b/Source/Server/Config/RuntimeConfig.h index 48566e5b..a2aa1d02 100644 --- a/Source/Server/Config/RuntimeConfig.h +++ b/Source/Server/Config/RuntimeConfig.h @@ -162,6 +162,9 @@ class RuntimeConfig // Port the master server lists for connections at MasterServerIp; int MasterServerPort = 50020; + // If true this reduces the amount of logging output to the bare minimum, only showing warnings/errors. + bool QuietLogging = false; + // If true register the server of the master servers list so others can see // and join it. bool Advertise = true; diff --git a/Source/Server/Server/Server.cpp b/Source/Server/Server/Server.cpp index 5f190163..a57bc478 100644 --- a/Source/Server/Server/Server.cpp +++ b/Source/Server/Server/Server.cpp @@ -115,6 +115,12 @@ bool Server::Init() } } + // Disable all but error messages if configured. + if (Config.QuietLogging) + { + SetQuietLogging(true); + } + // Determine game type. if (!ParseGameType(Config.GameType.c_str(), ServerGameType)) { @@ -298,7 +304,7 @@ bool Server::Init() } } -#define WriteState(State, bEnabled) WriteLog(bEnabled ? ConsoleColor::Green : ConsoleColor::Red, "", "Log", "%-25s: %s", State, bEnabled ? "Enabled" : "Disabled"); +#define WriteState(State, bEnabled) WriteLog(false, bEnabled ? ConsoleColor::Green : ConsoleColor::Red, "", "Log", "%-25s: %s", State, bEnabled ? "Enabled" : "Disabled"); WriteState("Blood Messages", !Config.DisableBloodMessages); WriteState("Blood Stains", !Config.DisableBloodStains); WriteState("Blood Ghosts", !Config.DisableGhosts); diff --git a/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.cpp b/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.cpp index e937fea3..fb39d852 100644 --- a/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.cpp +++ b/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.cpp @@ -446,7 +446,10 @@ void Frpg2ReliableUdpPacketStream::Handle_HBT(const Frpg2ReliableUdpPacket& Pack SequenceIndexAcked = std::max(SequenceIndexAcked, InRemoteAck); } - Send_HBT(); + if (!IsClient) + { + Send_HBT(); + } } void Frpg2ReliableUdpPacketStream::Handle_FIN(const Frpg2ReliableUdpPacket& Packet) @@ -775,6 +778,11 @@ void Frpg2ReliableUdpPacketStream::HandleOutgoing() } } +void Frpg2ReliableUdpPacketStream::Heartbeat() +{ + Send_HBT(); +} + bool Frpg2ReliableUdpPacketStream::Pump() { // Mark as connection closed after we have sent everything in the queue. @@ -796,6 +804,17 @@ bool Frpg2ReliableUdpPacketStream::Pump() return true; } + // If connected, and outgoing, send a heartbeat now and again. + if (State == Frpg2ReliableUdpStreamState::Established && IsClient) + { + double Elapsed = GetSeconds() - LastHeartbeatTime; + if (Elapsed > 5.0f) + { + Heartbeat(); + LastHeartbeatTime = GetSeconds(); + } + } + // If connecting periodically resend the syn until we get a response. This helps punch a // hole through NAT if required. if (State == Frpg2ReliableUdpStreamState::Connecting) diff --git a/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.h b/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.h index 143008f5..879c568d 100644 --- a/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.h +++ b/Source/Server/Server/Streams/Frpg2ReliableUdpPacketStream.h @@ -56,6 +56,9 @@ class Frpg2ReliableUdpPacketStream // Diassembles a messages into a human-readable string. std::string Disassemble(const Frpg2ReliableUdpPacket& Packet); + // Sends a heartbeat to the remote server. + void Heartbeat(); + protected: bool DecodeReliablePacket(const Frpg2UdpPacket& Packet, Frpg2ReliableUdpPacket& Message); @@ -106,6 +109,8 @@ class Frpg2ReliableUdpPacketStream double LastPacketRecievedTime = 0.0; double LastAckSendTime = 0.0; + double LastHeartbeatTime = 0.0f; + std::string SteamId = ""; // Ack sequences that we have sent replies with DAT_ACK, used to determine @@ -153,15 +158,15 @@ class Frpg2ReliableUdpPacketStream const int MAX_PACKETS_IN_FLIGHT = 32; // We reeeeeeeaaaallly want this to be exponential backoff, but this works for now. - const float RETRANSMIT_INTERVAL = 0.5f; // 500ms + const float RETRANSMIT_INTERVAL = 1.0f; // 1000 ms - const float RETRANSMIT_CYCLE_INTERVAL = 0.2f; // 200ms + const float RETRANSMIT_CYCLE_INTERVAL = 0.2f; // 200 ms #ifdef _DEBUG // Makes debugging easier. const uint32_t RETRANSMIT_MAX_ATTEMPTS = std::numeric_limits::max(); #else - const uint32_t RETRANSMIT_MAX_ATTEMPTS = 32; + const uint32_t RETRANSMIT_MAX_ATTEMPTS = 160; // 160 * 0.2 = Will give up after trying to retransmiting for 30 seconds #endif const float RESEND_SYN_INTERVAL = 0.5f; @@ -169,7 +174,7 @@ class Frpg2ReliableUdpPacketStream const double MIN_TIME_BETWEEN_RESEND_ACK = 0.15; // How many seconds to wait for a graceful disconnection. - const double CONNECTION_CLOSE_TIMEOUT = 3.0; + const double CONNECTION_CLOSE_TIMEOUT = 5.0; // How many values ACK increases before it rolls over. const uint32_t MAX_ACK_VALUE = 4096; diff --git a/Source/Server/Server/Streams/Frpg2UdpPacketStream.cpp b/Source/Server/Server/Streams/Frpg2UdpPacketStream.cpp index 78b18fd4..684cfda7 100644 --- a/Source/Server/Server/Streams/Frpg2UdpPacketStream.cpp +++ b/Source/Server/Server/Streams/Frpg2UdpPacketStream.cpp @@ -28,6 +28,7 @@ Frpg2UdpPacketStream::Frpg2UdpPacketStream(std::shared_ptr InConn : Connection(InConnection) , CwcKey(InCwcKey) , AuthToken(InAuthToken) + , IsClient(AsClient) { if (AsClient) { diff --git a/Source/Server/Server/Streams/Frpg2UdpPacketStream.h b/Source/Server/Server/Streams/Frpg2UdpPacketStream.h index 8a0c97e8..706edb1f 100644 --- a/Source/Server/Server/Streams/Frpg2UdpPacketStream.h +++ b/Source/Server/Server/Streams/Frpg2UdpPacketStream.h @@ -51,6 +51,8 @@ class Frpg2UdpPacketStream bool InErrorState = false; + bool IsClient = false; + private: double LastActivityTime; diff --git a/Source/Shared/Core/Utils/Logging.cpp b/Source/Shared/Core/Utils/Logging.cpp index 35faec8f..a59ff30a 100644 --- a/Source/Shared/Core/Utils/Logging.cpp +++ b/Source/Shared/Core/Utils/Logging.cpp @@ -19,8 +19,14 @@ namespace { std::mutex RecentMessageMutex; std::list RecentMessages; + bool QuietLoggingEnabled = false; }; +void SetQuietLogging(bool enabled) +{ + QuietLoggingEnabled = enabled; +} + std::list GetRecentLogs() { std::scoped_lock lock(RecentMessageMutex); @@ -73,8 +79,13 @@ void WriteLogStatic(ConsoleColor Color, const char* Source, const char* Level, c } } -void WriteLog(ConsoleColor Color, const char* Source, const char* Level, const char* Format, ...) +void WriteLog(bool QuietLoggable, ConsoleColor Color, const char* Source, const char* Level, const char* Format, ...) { + if (QuietLoggingEnabled && !QuietLoggable) + { + return; + } + char buffer[256]; char* buffer_to_use = buffer; diff --git a/Source/Shared/Core/Utils/Logging.h b/Source/Shared/Core/Utils/Logging.h index b6bd4b0f..5ce7ca53 100644 --- a/Source/Shared/Core/Utils/Logging.h +++ b/Source/Shared/Core/Utils/Logging.h @@ -27,35 +27,38 @@ struct LogMessage std::string Message; }; +// Disbale all but error messages. +void SetQuietLogging(bool enabled); + // Gets the most recent log messages, so they can be displayed in webui or other places. std::list GetRecentLogs(); // Writes a given entry into the output log. -void WriteLog(ConsoleColor Color, const char* Source, const char* Level, const char* Format, ...); +void WriteLog(bool QuietLoggable, ConsoleColor Color, const char* Source, const char* Level, const char* Format, ...); // Various macros for different log levels. #if defined(_DEBUG) -#define Verbose(Format, ...) WriteLog(ConsoleColor::Grey, "", "Verbose", Format, ##__VA_ARGS__); +#define Verbose(Format, ...) WriteLog(false, ConsoleColor::Grey, "", "Verbose", Format, ##__VA_ARGS__); #else #define Verbose(Format, ...) #endif -#define Log(Format, ...) WriteLog(ConsoleColor::Grey, "", "Log", Format, ##__VA_ARGS__); -#define Success(Format, ...) WriteLog(ConsoleColor::Green, "", "Success", Format, ##__VA_ARGS__); -#define Warning(Format, ...) WriteLog(ConsoleColor::Yellow, "", "Warning", Format, ##__VA_ARGS__); -#define Error(Format, ...) WriteLog(ConsoleColor::Red, "", "Error", Format, ##__VA_ARGS__); -#define Fatal(Format, ...) WriteLog(ConsoleColor::Red, "", "Fatal", Format, ##__VA_ARGS__); Ensure(false); +#define Log(Format, ...) WriteLog(false, ConsoleColor::Grey, "", "Log", Format, ##__VA_ARGS__); +#define Success(Format, ...) WriteLog(true, ConsoleColor::Green, "", "Success", Format, ##__VA_ARGS__); +#define Warning(Format, ...) WriteLog(true, ConsoleColor::Yellow, "", "Warning", Format, ##__VA_ARGS__); +#define Error(Format, ...) WriteLog(true, ConsoleColor::Red, "", "Error", Format, ##__VA_ARGS__); +#define Fatal(Format, ...) WriteLog(true, ConsoleColor::Red, "", "Fatal", Format, ##__VA_ARGS__); Ensure(false); // Same as the ones above but allows you to define the values of the "Source" column. #if defined(_DEBUG) -#define VerboseS(Source, Format, ...) WriteLog(ConsoleColor::Grey, Source, "Verbose", Format, ##__VA_ARGS__); +#define VerboseS(Source, Format, ...) WriteLog(false, ConsoleColor::Grey, Source, "Verbose", Format, ##__VA_ARGS__); #else #define VerboseS(Source, Format, ...) #endif -#define LogS(Source, Format, ...) WriteLog(ConsoleColor::Grey, Source, "Log", Format, ##__VA_ARGS__); -#define SuccessS(Source, Format, ...) WriteLog(ConsoleColor::Green, Source, "Success", Format, ##__VA_ARGS__); -#define WarningS(Source, Format, ...) WriteLog(ConsoleColor::Yellow, Source, "Warning", Format, ##__VA_ARGS__); -#define ErrorS(Source, Format, ...) WriteLog(ConsoleColor::Red, Source, "Error", Format, ##__VA_ARGS__); -#define FatalS(Source, Format, ...) WriteLog(ConsoleColor::Red, Source, "Fatal", Format, ##__VA_ARGS__); Ensure(false); +#define LogS(Source, Format, ...) WriteLog(false, ConsoleColor::Grey, Source, "Log", Format, ##__VA_ARGS__); +#define SuccessS(Source, Format, ...) WriteLog(true, ConsoleColor::Green, Source, "Success", Format, ##__VA_ARGS__); +#define WarningS(Source, Format, ...) WriteLog(true, ConsoleColor::Yellow, Source, "Warning", Format, ##__VA_ARGS__); +#define ErrorS(Source, Format, ...) WriteLog(true, ConsoleColor::Red, Source, "Error", Format, ##__VA_ARGS__); +#define FatalS(Source, Format, ...) WriteLog(true, ConsoleColor::Red, Source, "Fatal", Format, ##__VA_ARGS__); Ensure(false); #ifdef _WIN32 #define Breakpoint() __debugbreak()