From 9c8d3af760e6dd65fac2e4f1405c99c214f15cb4 Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Wed, 13 Mar 2024 22:53:43 +0300 Subject: [PATCH 1/9] netsocket: `socketHasIPv4` and `socketHasIPv6` should accept socket as const Signed-off-by: Pavel Solodovnikov --- lib/netplay/netsocket.cpp | 4 ++-- lib/netplay/netsocket.h | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/lib/netplay/netsocket.cpp b/lib/netplay/netsocket.cpp index 7d77f9ff839..a5b3dea1101 100644 --- a/lib/netplay/netsocket.cpp +++ b/lib/netplay/netsocket.cpp @@ -1550,7 +1550,7 @@ void socketArrayClose(Socket **sockets, size_t maxSockets) std::fill(sockets, sockets + maxSockets, (Socket *)nullptr); // Set the pointers to NULL. } -WZ_DECL_NONNULL(1) bool socketHasIPv4(Socket *sock) +WZ_DECL_NONNULL(1) bool socketHasIPv4(const Socket *sock) { if (sock->fd[SOCK_IPV4_LISTEN] != INVALID_SOCKET) { @@ -1573,7 +1573,7 @@ WZ_DECL_NONNULL(1) bool socketHasIPv4(Socket *sock) } } -WZ_DECL_NONNULL(1) bool socketHasIPv6(Socket *sock) +WZ_DECL_NONNULL(1) bool socketHasIPv6(const Socket *sock) { return sock->fd[SOCK_IPV6_LISTEN] != INVALID_SOCKET; } diff --git a/lib/netplay/netsocket.h b/lib/netplay/netsocket.h index 9cead953bdc..c21507ccfd5 100644 --- a/lib/netplay/netsocket.h +++ b/lib/netplay/netsocket.h @@ -102,8 +102,8 @@ WZ_DECL_NONNULL(1) void socketClose(Socket *sock); ///< Des Socket *socketOpenAny(const SocketAddress *addr, unsigned timeout); ///< Opens a Socket, using the first address that works in addr. size_t socketArrayOpen(Socket **sockets, size_t maxSockets, const SocketAddress *addr, unsigned timeout); ///< Opens up to maxSockets Sockets, of the types listed in addr. void socketArrayClose(Socket **sockets, size_t maxSockets); ///< Closes all Sockets in the array. -WZ_DECL_NONNULL(1) bool socketHasIPv4(Socket *sock); -WZ_DECL_NONNULL(1) bool socketHasIPv6(Socket *sock); +WZ_DECL_NONNULL(1) bool socketHasIPv4(const Socket *sock); +WZ_DECL_NONNULL(1) bool socketHasIPv6(const Socket *sock); WZ_DECL_NONNULL(1) char const *getSocketTextAddress(Socket const *sock); ///< Gets a string with the socket address. std::vector ipv4_AddressString_To_NetBinary(const std::string& ipv4Address); From 8d5c7d1b8b57af25b6c837c73eb8dc0fe46c6fc7 Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Sun, 17 Mar 2024 12:41:35 +0300 Subject: [PATCH 2/9] netsocket: remove unused functions `socketArrayOpen` and `socketArrayClose` weren't used anywhere, so remove them. Signed-off-by: Pavel Solodovnikov --- lib/netplay/netsocket.cpp | 23 ----------------------- lib/netplay/netsocket.h | 2 -- 2 files changed, 25 deletions(-) diff --git a/lib/netplay/netsocket.cpp b/lib/netplay/netsocket.cpp index a5b3dea1101..68341543d4d 100644 --- a/lib/netplay/netsocket.cpp +++ b/lib/netplay/netsocket.cpp @@ -1527,29 +1527,6 @@ Socket *socketOpenAny(const SocketAddress *addr, unsigned timeout) return ret; } -size_t socketArrayOpen(Socket **sockets, size_t maxSockets, const SocketAddress *addr, unsigned timeout) -{ - size_t i = 0; - while (i < maxSockets && addr != nullptr) - { - if (addr->ai_family == AF_INET || addr->ai_family == AF_INET6) - { - sockets[i] = socketOpen(addr, timeout); - i += sockets[i] != nullptr; - } - - addr = addr->ai_next; - } - std::fill(sockets + i, sockets + maxSockets, (Socket *)nullptr); - return i; -} - -void socketArrayClose(Socket **sockets, size_t maxSockets) -{ - std::for_each(sockets, sockets + maxSockets, socketClose); // Close any open sockets. - std::fill(sockets, sockets + maxSockets, (Socket *)nullptr); // Set the pointers to NULL. -} - WZ_DECL_NONNULL(1) bool socketHasIPv4(const Socket *sock) { if (sock->fd[SOCK_IPV4_LISTEN] != INVALID_SOCKET) diff --git a/lib/netplay/netsocket.h b/lib/netplay/netsocket.h index c21507ccfd5..0dbbcefadbc 100644 --- a/lib/netplay/netsocket.h +++ b/lib/netplay/netsocket.h @@ -100,8 +100,6 @@ Socket *socketListen(unsigned int port); ///< Cre WZ_DECL_NONNULL(1) Socket *socketAccept(Socket *sock); ///< Accepts an incoming Socket connection from a listening Socket. WZ_DECL_NONNULL(1) void socketClose(Socket *sock); ///< Destroys the Socket. Socket *socketOpenAny(const SocketAddress *addr, unsigned timeout); ///< Opens a Socket, using the first address that works in addr. -size_t socketArrayOpen(Socket **sockets, size_t maxSockets, const SocketAddress *addr, unsigned timeout); ///< Opens up to maxSockets Sockets, of the types listed in addr. -void socketArrayClose(Socket **sockets, size_t maxSockets); ///< Closes all Sockets in the array. WZ_DECL_NONNULL(1) bool socketHasIPv4(const Socket *sock); WZ_DECL_NONNULL(1) bool socketHasIPv6(const Socket *sock); From 7f3e9d489068380984dddd9ed402a1da73947f3e Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 17:31:00 +0300 Subject: [PATCH 3/9] netplay: remove unused variable Signed-off-by: Pavel Solodovnikov --- lib/netplay/netplay.cpp | 2 -- 1 file changed, 2 deletions(-) diff --git a/lib/netplay/netplay.cpp b/lib/netplay/netplay.cpp index f0d3d199a12..deb37c8d056 100644 --- a/lib/netplay/netplay.cpp +++ b/lib/netplay/netplay.cpp @@ -258,8 +258,6 @@ static Socket *bsocket = nullptr; ///< Socket used to talk to t static Socket *connected_bsocket[MAX_CONNECTED_PLAYERS] = { nullptr }; ///< Sockets used to talk to clients (host only). static SocketSet *socket_set = nullptr; -WZ_THREAD *upnpdiscover; - static struct UPNPUrls urls; static struct IGDdatas data; From fea36d755eda4529fd9044891751c5ed0521f014 Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 18:04:21 +0300 Subject: [PATCH 4/9] netplay: factor `WZFile` out of `netplay.h/cpp` Signed-off-by: Pavel Solodovnikov --- lib/netplay/netplay.cpp | 33 -------------------- lib/netplay/netplay.h | 37 ++-------------------- lib/netplay/wzfile.cpp | 59 +++++++++++++++++++++++++++++++++++ lib/netplay/wzfile.h | 68 +++++++++++++++++++++++++++++++++++++++++ 4 files changed, 130 insertions(+), 67 deletions(-) create mode 100644 lib/netplay/wzfile.cpp create mode 100644 lib/netplay/wzfile.h diff --git a/lib/netplay/netplay.cpp b/lib/netplay/netplay.cpp index deb37c8d056..447af51430a 100644 --- a/lib/netplay/netplay.cpp +++ b/lib/netplay/netplay.cpp @@ -353,39 +353,6 @@ static char const *versionString = version_getVersionString(); #include "lib/netplay/netplay_config.h" -static inline bool physfs_file_safe_close_impl(PHYSFS_file* f) -{ - if (!f) - { - return false; - } - if (!PHYSFS_isInit()) - { - return false; - } - PHYSFS_close(f); - f = nullptr; - return true; -} - -void physfs_file_safe_close(PHYSFS_file* f) -{ - physfs_file_safe_close_impl(f); -} - -WZFile::~WZFile() -{ } - -bool WZFile::closeFile() -{ - if (!handle_) - { - return false; - } - PHYSFS_file *file = handle_.release(); - return physfs_file_safe_close_impl(file); -} - const std::vector& NET_getDownloadingWzFiles() { return DownloadingWzFiles; diff --git a/lib/netplay/netplay.h b/lib/netplay/netplay.h index eb9f264c4c5..024d4611b7a 100644 --- a/lib/netplay/netplay.h +++ b/lib/netplay/netplay.h @@ -29,10 +29,13 @@ #include "lib/framework/crc.h" #include "src/factionid.h" #include "nettypes.h" +#include "wzfile.h" + #include #include #include #include + // Lobby Connection errors enum LOBBY_ERROR_TYPES @@ -217,40 +220,6 @@ struct SYNC_COUNTER uint16_t rejected; }; -void physfs_file_safe_close(PHYSFS_file* f); - -struct WZFile -{ -public: -// WZFile() : handle_(nullptr, physfs_file_safe_close), size(0), pos(0) { hash.setZero(); } - WZFile(PHYSFS_file *handle, const std::string &filename, Sha256 hash, uint32_t size = 0) : handle_(handle, physfs_file_safe_close), filename(filename), hash(hash), size(size), pos(0) {} - - ~WZFile(); - - // Prevent copies - WZFile(const WZFile&) = delete; - void operator=(const WZFile&) = delete; - - // Allow move semantics - WZFile(WZFile&& other) = default; - WZFile& operator=(WZFile&& other) = default; - -public: - bool closeFile(); - inline PHYSFS_file* handle() const - { - return handle_.get(); - } - -private: - std::unique_ptr handle_; -public: - std::string filename; - Sha256 hash; - uint32_t size = 0; - uint32_t pos = 0; // Current position, the range [0; currPos[ has been sent or received already. -}; - enum class AIDifficulty : int8_t { SUPEREASY, diff --git a/lib/netplay/wzfile.cpp b/lib/netplay/wzfile.cpp new file mode 100644 index 00000000000..0dad7c2517d --- /dev/null +++ b/lib/netplay/wzfile.cpp @@ -0,0 +1,59 @@ +/* + This file is part of Warzone 2100. + Copyright (C) 2024 Warzone 2100 Project + + Warzone 2100 is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation; either version 2 of the License, or + (at your option) any later version. + + Warzone 2100 is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with Warzone 2100; if not, write to the Free Software + Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +*/ +/** + * @file wzfile.cpp + * + * `WZFile` thin wrapper over physfs file handle. Used for network code related to + * downloading files. + */ + +#include "wzfile.h" + +static inline bool physfs_file_safe_close_impl(PHYSFS_file* f) +{ + if (!f) + { + return false; + } + if (!PHYSFS_isInit()) + { + return false; + } + PHYSFS_close(f); + f = nullptr; + return true; +} + +void physfs_file_safe_close(PHYSFS_file* f) +{ + physfs_file_safe_close_impl(f); +} + +WZFile::~WZFile() +{ } + +bool WZFile::closeFile() +{ + if (!handle_) + { + return false; + } + PHYSFS_file* file = handle_.release(); + return physfs_file_safe_close_impl(file); +} diff --git a/lib/netplay/wzfile.h b/lib/netplay/wzfile.h new file mode 100644 index 00000000000..77855b46f4b --- /dev/null +++ b/lib/netplay/wzfile.h @@ -0,0 +1,68 @@ +/* + This file is part of Warzone 2100. + Copyright (C) 2024 Warzone 2100 Project + + Warzone 2100 is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation; either version 2 of the License, or + (at your option) any later version. + + Warzone 2100 is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with Warzone 2100; if not, write to the Free Software + Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +*/ +/* + * @file wzfile.h + * + * `WZFile` thin wrapper over physfs file handle. Used for network code related to + * downloading files. + */ + +#pragma once + +#include "lib/framework/crc.h" + +#include + +#include +#include +#include + +void physfs_file_safe_close(PHYSFS_file* f); + +struct WZFile +{ +public: + + WZFile(PHYSFS_file* handle, const std::string& filename, Sha256 hash, uint32_t size = 0) : handle_(handle, physfs_file_safe_close), filename(filename), hash(hash), size(size), pos(0) {} + + ~WZFile(); + + // Prevent copies + WZFile(const WZFile&) = delete; + void operator=(const WZFile&) = delete; + + // Allow move semantics + WZFile(WZFile&& other) = default; + WZFile& operator=(WZFile&& other) = default; + +public: + bool closeFile(); + inline PHYSFS_file* handle() const + { + return handle_.get(); + } + +private: + std::unique_ptr handle_; +public: + std::string filename; + Sha256 hash; + uint32_t size = 0; + uint32_t pos = 0; // Current position, the range [0; currPos[ has been sent or received already. +}; From 9f07ebc79acf0992bd2c28d07073e4509c7a4ef5 Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 18:21:42 +0300 Subject: [PATCH 5/9] netplay: remove unused function declarations Signed-off-by: Pavel Solodovnikov --- lib/netplay/netplay.h | 2 -- 1 file changed, 2 deletions(-) diff --git a/lib/netplay/netplay.h b/lib/netplay/netplay.h index 024d4611b7a..5b8bcfcd26e 100644 --- a/lib/netplay/netplay.h +++ b/lib/netplay/netplay.h @@ -444,7 +444,6 @@ bool NETgetJoinPreferenceIPv6(); void NETsetDefaultMPHostFreeChatPreference(bool enabled); bool NETgetDefaultMPHostFreeChatPreference(); -bool NETsetupTCPIP(const char *machine); void NETsetGamePassword(const char *password); void NETBroadcastPlayerInfo(uint32_t index); void NETBroadcastTwoPlayerInfo(uint32_t index1, uint32_t index2); @@ -470,7 +469,6 @@ bool NETGameIsLocked(); void NETGameLocked(bool flag); void NETresetGamePassword(); bool NETregisterServer(int state); -bool NETprocessQueuedServerUpdates(); void NETsetPlayerConnectionStatus(CONNECTION_STATUS status, unsigned player); ///< Cumulative, except that CONNECTIONSTATUS_NORMAL resets. bool NETcheckPlayerConnectionStatus(CONNECTION_STATUS status, unsigned player); ///< True iff connection status icon hasn't expired for this player. CONNECTIONSTATUS_NORMAL means any status, NET_ALL_PLAYERS means all players. From 126cff988cc10a69f17a9fb1a9a938b5d62dd35b Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 18:26:29 +0300 Subject: [PATCH 6/9] netplay: remove dependency cycle between `netlog.h` and `netplay.h` Signed-off-by: Pavel Solodovnikov --- lib/netplay/netlog.h | 7 ++++--- lib/netplay/netplay.h | 3 +-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/lib/netplay/netlog.h b/lib/netplay/netlog.h index 3f3d6396f2d..e2862785484 100644 --- a/lib/netplay/netlog.h +++ b/lib/netplay/netlog.h @@ -1,7 +1,7 @@ /* This file is part of Warzone 2100. Copyright (C) 1999-2004 Eidos Interactive - Copyright (C) 2005-2020 Warzone 2100 Project + Copyright (C) 2005-2024 Warzone 2100 Project Warzone 2100 is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by @@ -20,9 +20,10 @@ #ifndef _netlog_h #define _netlog_h -#include "lib/framework/frame.h" +#include "lib/framework/types.h" +#include "lib/framework/wzglobal.h" -#include "netplay.h" +#include bool NETstartLogging(); bool NETstopLogging(); diff --git a/lib/netplay/netplay.h b/lib/netplay/netplay.h index 5b8bcfcd26e..a07175418ac 100644 --- a/lib/netplay/netplay.h +++ b/lib/netplay/netplay.h @@ -30,6 +30,7 @@ #include "src/factionid.h" #include "nettypes.h" #include "wzfile.h" +#include "netlog.h" #include #include @@ -431,8 +432,6 @@ bool NEThostGame(const char *SessionName, const char *PlayerName, bool spectator bool NETchangePlayerName(UDWORD player, char *newName);// change a players name. void NETfixDuplicatePlayerNames(); // Change a player's name automatically, if there are duplicates. -#include "netlog.h" - void NETsetMasterserverName(const char *hostname); const char *NETgetMasterserverName(); void NETsetMasterserverPort(unsigned int port); From 766479afc8c966b6b3f6edf0c518ca255389fb85 Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 18:41:32 +0300 Subject: [PATCH 7/9] netplay: update copyright year to 2024 Signed-off-by: Pavel Solodovnikov --- lib/netplay/netplay.cpp | 2 +- lib/netplay/netplay.h | 2 +- lib/netplay/netsocket.h | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/netplay/netplay.cpp b/lib/netplay/netplay.cpp index 447af51430a..4480ad44f46 100644 --- a/lib/netplay/netplay.cpp +++ b/lib/netplay/netplay.cpp @@ -1,7 +1,7 @@ /* This file is part of Warzone 2100. Copyright (C) 1999-2004 Eidos Interactive - Copyright (C) 2005-2020 Warzone 2100 Project + Copyright (C) 2005-2024 Warzone 2100 Project Warzone 2100 is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by diff --git a/lib/netplay/netplay.h b/lib/netplay/netplay.h index a07175418ac..ae68013bcf9 100644 --- a/lib/netplay/netplay.h +++ b/lib/netplay/netplay.h @@ -1,7 +1,7 @@ /* This file is part of Warzone 2100. Copyright (C) 1999-2004 Eidos Interactive - Copyright (C) 2005-2020 Warzone 2100 Project + Copyright (C) 2005-2024 Warzone 2100 Project Warzone 2100 is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by diff --git a/lib/netplay/netsocket.h b/lib/netplay/netsocket.h index 0dbbcefadbc..eaf2bcbf012 100644 --- a/lib/netplay/netsocket.h +++ b/lib/netplay/netsocket.h @@ -1,7 +1,7 @@ /* This file is part of Warzone 2100. Copyright (C) 1999-2004 Eidos Interactive - Copyright (C) 2005-2020 Warzone 2100 Project + Copyright (C) 2005-2024 Warzone 2100 Project Warzone 2100 is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by From 101dd0fe7946541fe70c38582621765094a9bc89 Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 19:23:23 +0300 Subject: [PATCH 8/9] netplay: extract `syncDebug*` to a separate source file Signed-off-by: Pavel Solodovnikov --- lib/netplay/netplay.cpp | 537 +--------------------------------- lib/netplay/netplay.h | 29 +- lib/netplay/sync_debug.cpp | 578 +++++++++++++++++++++++++++++++++++++ lib/netplay/sync_debug.h | 57 ++++ 4 files changed, 637 insertions(+), 564 deletions(-) create mode 100644 lib/netplay/sync_debug.cpp create mode 100644 lib/netplay/sync_debug.h diff --git a/lib/netplay/netplay.cpp b/lib/netplay/netplay.cpp index 4480ad44f46..ba8f64ba208 100644 --- a/lib/netplay/netplay.cpp +++ b/lib/netplay/netplay.cpp @@ -49,6 +49,7 @@ #include "netreplay.h" #include "netsocket.h" #include "netpermissions.h" +#include "sync_debug.h" #include #if (defined(__GNUC__) || defined(__clang__)) && !defined(__INTEL_COMPILER) @@ -83,15 +84,10 @@ # include "lib/framework/cocoa_wrapper.h" #endif -#if defined(WZ_OS_LINUX) && defined(__GLIBC__) -#include // Nonfatal runtime backtraces. -#endif // defined(WZ_OS_LINUX) && defined(__GLIBC__) - // WARNING !!! This is initialised via configuration.c !!! char masterserver_name[255] = {'\0'}; static unsigned int masterserver_port = 0, gameserver_port = 0; static bool bJoinPrefTryIPv6First = true; -static uint32_t verboseDebugOutputAllSyncLogsUntilGameTime = 0; static bool bDefaultHostFreeChatEnabled = true; // This is for command line argument override @@ -126,7 +122,6 @@ static void NETplayerCloseSocket(UDWORD index, bool quietSocketClose); static void NETplayerLeaving(UDWORD player, bool quietSocketClose = false); // Cleanup sockets on player leaving (nicely) static void NETplayerDropped(UDWORD player); // Broadcast NET_PLAYER_DROPPED & cleanup static void NETallowJoining(); -static void recvDebugSync(NETQUEUE queue); static void NETfixPlayerCount(); /* * Network globals, these are part of the new network API @@ -5100,18 +5095,6 @@ const char *NETgetMasterserverName() return masterserver_name; } -// Set whether verbose debug mode - outputting the current player's sync log for every single game tick - is enabled -// WARNING: This may significantly impact performance *and* will fill up your drive with a lot of logs data! -// It is only intended to be used for debugging issues such as: replays desyncing when gameplay does not, etc. (And don't let the game run too long!) -void NET_setDebuggingModeVerboseOutputAllSyncLogs(uint32_t untilGameTime) -{ - verboseDebugOutputAllSyncLogsUntilGameTime = untilGameTime; - if (verboseDebugOutputAllSyncLogsUntilGameTime) - { - debug(LOG_INFO, "WARNING: Verbose sync log output is enabled!"); - } -} - /*! * Set the masterserver port * \param port The port of the masterserver to connect to @@ -5235,524 +5218,6 @@ bool NETcheckPlayerConnectionStatus(CONNECTION_STATUS status, unsigned player) return realTime < NET_PlayerConnectionStatus[status][player]; } -struct SyncDebugEntry -{ - char const *function; -}; - -struct SyncDebugString : public SyncDebugEntry -{ - void set(uint32_t &crc, char const *f, char const *string) - { - function = f; - crc = crcSum(crc, function, strlen(function) + 1); - crc = crcSum(crc, string, strlen(string) + 1); - } - int snprint(char *buf, size_t bufSize, char const *&string) const - { - int ret = snprintf(buf, bufSize, "[%s] %s\n", function, string); - string += strlen(string) + 1; - return ret; - } -}; - -struct SyncDebugValueChange : public SyncDebugEntry -{ - void set(uint32_t &crc, char const *f, char const *vn, int nv, int i) - { - function = f; - variableName = vn; - newValue = nv; - id = i; - uint32_t valueBytes = htonl(newValue); - crc = crcSum(crc, function, strlen(function) + 1); - crc = crcSum(crc, variableName, strlen(variableName) + 1); - crc = crcSum(crc, &valueBytes, 4); - } - int snprint(char *buf, size_t bufSize) const - { - if (id != -1) - { - return snprintf(buf, bufSize, "[%s] %d %s = %d\n", function, id, variableName, newValue); - } - return snprintf(buf, bufSize, "[%s] %s = %d\n", function, variableName, newValue); - } - - int newValue; - int id; - char const *variableName; -}; - -struct SyncDebugIntList : public SyncDebugEntry -{ - void set(uint32_t &crc, char const *f, char const *s, int const *ints, size_t num) - { - function = f; - string = s; - uint32_t valueBytes[40]; - numInts = std::min(num, ARRAY_SIZE(valueBytes)); - for (unsigned n = 0; n < numInts; ++n) - { - valueBytes[n] = htonl(ints[n]); - } - crc = crcSum(crc, valueBytes, 4 * numInts); - } - int snprint(char *buf, size_t bufSize, int const *&ints) const - { - size_t index = 0; - if (index < bufSize) - { - index += snprintf(buf + index, bufSize - index, "[%s] ", function); - } - if (index < bufSize) - { - switch (numInts) - { - case 0: index += snprintf(buf + index, bufSize - index, "%s", string); break; - case 1: index += snprintf(buf + index, bufSize - index, string, ints[0]); break; - case 2: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1]); break; - case 3: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2]); break; - case 4: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3]); break; - case 5: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4]); break; - case 6: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5]); break; - case 7: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6]); break; - case 8: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7]); break; - case 9: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8]); break; - case 10: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9]); break; - case 11: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10]); break; - case 12: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11]); break; - case 13: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12]); break; - case 14: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13]); break; - case 15: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14]); break; - case 16: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15]); break; - case 17: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16]); break; - case 18: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17]); break; - case 19: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18]); break; - case 20: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19]); break; - case 21: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20]); break; - case 22: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21]); break; - case 23: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22]); break; - case 24: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23]); break; - case 25: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24]); break; - case 26: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25]); break; - case 27: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26]); break; - case 28: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27]); break; - case 29: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28]); break; - case 30: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29]); break; - case 31: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30]); break; - case 32: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31]); break; - case 33: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32]); break; - case 34: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33]); break; - case 35: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34]); break; - case 36: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35]); break; - case 37: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36]); break; - case 38: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36], ints[37]); break; - case 39: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36], ints[37], ints[38]); break; - case 40: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36], ints[37], ints[38], ints[39]); break; - default: index += snprintf(buf + index, bufSize - index, "Too many ints in intlist."); break; - } - } - if (index < bufSize) - { - index += snprintf(buf + index, bufSize - index, "\n"); - } - ints += numInts; - return index; - } - - char const *string; - unsigned numInts; -}; - -struct SyncDebugLog -{ - SyncDebugLog() : time(0), crc(0x00000000) {} - void clear() - { - log.clear(); - time = 0; - crc = 0x00000000; - //printf("Freeing %d strings, %d valueChanges, %d intLists, %d chars, %d ints\n", (int)strings.size(), (int)valueChanges.size(), (int)intLists.size(), (int)chars.size(), (int)ints.size()); - strings.clear(); - valueChanges.clear(); - intLists.clear(); - chars.clear(); - ints.clear(); - } - void string(char const *f, char const *s) - { - size_t offset = chars.size(); - chars.resize(chars.size() + strlen(s) + 1); - char *buf = &chars[offset]; - strcpy(buf, s); - - strings.resize(strings.size() + 1); - strings.back().set(crc, f, buf); - - log.push_back('s'); - } - void valueChange(char const *f, char const *vn, int nv, int i) - { - valueChanges.resize(valueChanges.size() + 1); - valueChanges.back().set(crc, f, vn, nv, i); - log.push_back('v'); - } - void intList(char const *f, char const *s, int *begin, size_t num) - { - size_t offset = ints.size(); - ints.resize(ints.size() + num); - int *buf = &ints[offset]; - std::copy(begin, begin + num, buf); - - intLists.resize(intLists.size() + 1); - intLists.back().set(crc, f, s, buf, num); - log.push_back('i'); - } - int snprint(char *buf, size_t bufSize) - { - SyncDebugString const *stringPtr = strings.empty() ? nullptr : &strings[0]; // .empty() check, since &strings[0] is undefined if strings is empty(), even if it's likely to work, anyway. - SyncDebugValueChange const *valueChangePtr = valueChanges.empty() ? nullptr : &valueChanges[0]; - SyncDebugIntList const *intListPtr = intLists.empty() ? nullptr : &intLists[0]; - char const *charPtr = chars.empty() ? nullptr : &chars[0]; - int const *intPtr = ints.empty() ? nullptr : &ints[0]; - - int index = 0; - for (size_t n = 0; n < log.size() && (size_t)index < bufSize; ++n) - { - char type = log[n]; - switch (type) - { - case 's': - index += stringPtr++->snprint(buf + index, bufSize - index, charPtr); - break; - case 'v': - index += valueChangePtr++->snprint(buf + index, bufSize - index); - break; - case 'i': - index += intListPtr++->snprint(buf + index, bufSize - index, intPtr); - break; - default: - abort(); - break; - } - } - return index; - } - uint32_t getGameTime() const - { - return time; - } - uint32_t getCrc() const - { - return ~crc; // Invert bits, since everyone else seems to do that with CRCs... - } - size_t getNumEntries() const - { - return log.size(); - } - void setGameTime(uint32_t newTime) - { - time = newTime; - } - void setCrc(uint32_t newCrc) - { - crc = ~newCrc; // Invert bits, since everyone else seems to do that with CRCs... - } - -private: - std::vector log; - uint32_t time; - uint32_t crc; - - std::vector strings; - std::vector valueChanges; - std::vector intLists; - - std::vector chars; - std::vector ints; - -private: - SyncDebugLog(SyncDebugLog const &)/* = delete*/; - SyncDebugLog &operator =(SyncDebugLog const &)/* = delete*/; -}; - -#define MAX_LEN_LOG_LINE 512 // From debug.c - no use printing something longer. -#define MAX_SYNC_HISTORY 12 - -static unsigned syncDebugNext = 0; -static SyncDebugLog syncDebugLog[MAX_SYNC_HISTORY]; -static uint32_t syncDebugExtraGameTime; -static uint32_t syncDebugExtraCrc; - -static uint32_t syncDebugNumDumps = 0; - -void _syncDebug(const char *function, const char *str, ...) -{ -#ifdef WZ_CC_MSVC - char const *f = function; while (*f != '\0') if (*f++ == ':') - { - function = f; // Strip "Class::" from "Class::myFunction". - } -#endif - - va_list ap; - char outputBuffer[MAX_LEN_LOG_LINE]; - - va_start(ap, str); - vssprintf(outputBuffer, str, ap); - va_end(ap); - - syncDebugLog[syncDebugNext].string(function, outputBuffer); -} - -void _syncDebugIntList(const char *function, const char *str, int *ints, size_t numInts) -{ -#ifdef WZ_CC_MSVC - char const *f = function; while (*f != '\0') if (*f++ == ':') - { - function = f; // Strip "Class::" from "Class::myFunction". - } -#endif - - syncDebugLog[syncDebugNext].intList(function, str, ints, numInts); -} - -void _syncDebugBacktrace(const char *function) -{ -#ifdef WZ_CC_MSVC - char const *f = function; while (*f != '\0') if (*f++ == ':') - { - function = f; // Strip "Class::" from "Class::myFunction". - } -#endif - - uint32_t backupCrc = syncDebugLog[syncDebugNext].getCrc(); // Ignore CRC changes from _syncDebug(), since identical backtraces can be printed differently. - -#if defined(WZ_OS_LINUX) && defined(__GLIBC__) - void *btv[20]; - unsigned num = backtrace(btv, sizeof(btv) / sizeof(*btv)); - char **btc = backtrace_symbols(btv, num); - unsigned i; - for (i = 1; i + 2 < num; ++i) // =1: Don't print "src/warzone2100(syncDebugBacktrace+0x16) [0x6312d1]". +2: Don't print last two lines of backtrace such as "/lib/libc.so.6(__libc_start_main+0xe6) [0x7f91e040ea26]", since the address varies (even with the same binary). - { - _syncDebug("BT", "%s", btc[i]); - } - free(btc); -#else - _syncDebug("BT", "Sorry, syncDebugBacktrace() not implemented on your system. Called from %s.", function); -#endif - - // Use CRC of something platform-independent, to avoid false positive desynchs. - backupCrc = ~crcSum(~backupCrc, function, strlen(function) + 1); - syncDebugLog[syncDebugNext].setCrc(backupCrc); -} - -uint32_t syncDebugGetCrc() -{ - return syncDebugLog[syncDebugNext].getCrc(); -} - -void syncDebugSetCrc(uint32_t crc) -{ - syncDebugLog[syncDebugNext].setCrc(crc); -} - -void resetSyncDebug() -{ - for (unsigned i = 0; i < MAX_SYNC_HISTORY; ++i) - { - syncDebugLog[i].clear(); - } - - syncDebugExtraGameTime = 0; - syncDebugExtraCrc = 0xFFFFFFFF; - - syncDebugNext = 0; - - syncDebugNumDumps = 0; -} - -GameCrcType nextDebugSync() -{ - uint32_t ret = syncDebugLog[syncDebugNext].getCrc(); - - // Save gameTime, so we know which CRC to compare with, later. - syncDebugLog[syncDebugNext].setGameTime(gameTime); - - // Go to next position, and free it ready for use. - syncDebugNext = (syncDebugNext + 1) % MAX_SYNC_HISTORY; - syncDebugLog[syncDebugNext].clear(); - - return (GameCrcType)ret; -} - -static void dumpDebugSyncImpl(uint8_t *buf, size_t bufLen, const char* fname) -{ - PHYSFS_file *fp = openSaveFile(fname); - if (!fp) - { - debug(LOG_ERROR, "Failed to open file for writing: %s", fname); - return; - } - ASSERT(bufLen <= static_cast(std::numeric_limits::max()), "bufLen (%zu) exceeds PHYSFS_uint32::max", bufLen); - WZ_PHYSFS_writeBytes(fp, buf, static_cast(bufLen)); - PHYSFS_close(fp); -} - -static void dumpDebugSync(uint8_t *buf, size_t bufLen, uint32_t time, unsigned player, bool syncError = true) -{ - char fname[100]; - ssprintf(fname, "logs/desync%u_p%u.txt", time, player); - - dumpDebugSyncImpl(buf, bufLen, fname); - - bool isSpectator = player < NetPlay.players.size() && NetPlay.players[player].isSpectator; - std::string typeDescription = (syncError) ? "sync error" : "sync log"; - std::string playerDescription = (isSpectator) ? "spectator" : "player"; - debug(LOG_ERROR, "Dumped %s %u's %s at gameTime %u to file: %s%s", playerDescription.c_str(), player, typeDescription.c_str(), time, WZ_PHYSFS_getRealDir_String(fname).c_str(), fname); -} - -static void sendDebugSync(uint8_t *buf, uint32_t bufLen, uint32_t time) -{ - // Save our own, before sending, so that if we have 2 clients running on the same computer, to guarantee that it is done saving before the other client saves on top. - dumpDebugSync(buf, bufLen, time, selectedPlayer); - - NETbeginEncode(NETbroadcastQueue(), NET_DEBUG_SYNC); - NETuint32_t(&time); - NETuint32_t(&bufLen); - NETbin(buf, bufLen); - NETend(); -} - -static uint8_t debugSyncTmpBuf[2000000]; - -static size_t dumpLocalDebugSyncLog(unsigned logIndex) -{ - size_t bufIndex = 0; - // Dump our version, and also erase it, so we only dump it at most once. - bufIndex += snprintf((char *)debugSyncTmpBuf + bufIndex, ARRAY_SIZE(debugSyncTmpBuf) - bufIndex, "===== BEGIN gameTime=%u, %zu entries, CRC 0x%08X =====\n", syncDebugLog[logIndex].getGameTime(), syncDebugLog[logIndex].getNumEntries(), syncDebugLog[logIndex].getCrc()); - bufIndex = MIN(bufIndex, ARRAY_SIZE(debugSyncTmpBuf)); // snprintf will not overflow debugSyncTmpBuf, but returns as much as it would have printed if possible. - bufIndex += syncDebugLog[logIndex].snprint((char *)debugSyncTmpBuf + bufIndex, ARRAY_SIZE(debugSyncTmpBuf) - bufIndex); - bufIndex = MIN(bufIndex, ARRAY_SIZE(debugSyncTmpBuf)); // snprintf will not overflow debugSyncTmpBuf, but returns as much as it would have printed if possible. - bufIndex += snprintf((char *)debugSyncTmpBuf + bufIndex, ARRAY_SIZE(debugSyncTmpBuf) - bufIndex, "===== END gameTime=%u, %zu entries, CRC 0x%08X =====\n", syncDebugLog[logIndex].getGameTime(), syncDebugLog[logIndex].getNumEntries(), syncDebugLog[logIndex].getCrc()); - bufIndex = MIN(bufIndex, ARRAY_SIZE(debugSyncTmpBuf)); // snprintf will not overflow debugSyncTmpBuf, but returns as much as it would have printed if possible. - - return bufIndex; -} - -static size_t dumpLocalDebugSyncLogByTime(uint32_t time) -{ - unsigned logIndex; - for (logIndex = 0; logIndex < MAX_SYNC_HISTORY; ++logIndex) - { - if (syncDebugLog[logIndex].getGameTime() == time) - { - break; // found the log index for this time - } - } - - if (logIndex >= MAX_SYNC_HISTORY) - { - // did not find it - debug(LOG_WARNING, "Couldn't find gameTime: %" PRIu32 " in history", time); - return 0; - } - - return dumpLocalDebugSyncLog(logIndex); -} - -static void recvDebugSync(NETQUEUE queue) -{ - uint32_t time = 0; - uint32_t bufLen = 0; - - NETbeginDecode(queue, NET_DEBUG_SYNC); - NETuint32_t(&time); - NETuint32_t(&bufLen); - bufLen = MIN(bufLen, ARRAY_SIZE(debugSyncTmpBuf)); - NETbin(debugSyncTmpBuf, bufLen); - NETend(); - - dumpDebugSync(debugSyncTmpBuf, bufLen, time, queue.index); - - // Also dump the debug sync log for this local client (if possible) - bufLen = dumpLocalDebugSyncLogByTime(time); - if (bufLen > 0) - { - dumpDebugSync(debugSyncTmpBuf, bufLen, time, selectedPlayer, false); - } -} - -void debugVerboseLogSyncIfNeeded() -{ - if (!verboseDebugOutputAllSyncLogsUntilGameTime || gameTime > verboseDebugOutputAllSyncLogsUntilGameTime) - { - return; - } - - auto bufLen = dumpLocalDebugSyncLogByTime(gameTime); - if (bufLen > 0) - { - char fname[100]; - ssprintf(fname, "logs/sync%u_p%u.txt", gameTime, selectedPlayer); - dumpDebugSyncImpl(debugSyncTmpBuf, bufLen, fname); - } -} - -bool checkDebugSync(uint32_t checkGameTime, GameCrcType checkCrc) -{ - if (checkGameTime == syncDebugLog[syncDebugNext].getGameTime()) // Can't happen - and syncDebugGameTime[] == 0, until just before sending the CRC, anyway. - { - debug(LOG_ERROR, "Huh? We aren't done yet..."); - return true; - } - - unsigned logIndex; - for (logIndex = 0; logIndex < MAX_SYNC_HISTORY; ++logIndex) - { - if (syncDebugLog[logIndex].getGameTime() == checkGameTime) - { - if ((GameCrcType)syncDebugLog[logIndex].getCrc() == checkCrc) - { - return true; // Check passed. (So far... There might still be more players to compare CRCs with.) - } - - debug(LOG_NET, "Non-matching crc for gameTime: %" PRIu32 "", checkGameTime); - break; // Check failed! - } - } - - if (logIndex >= MAX_SYNC_HISTORY && syncDebugExtraGameTime == checkGameTime) - { - if ((GameCrcType)syncDebugExtraCrc == checkCrc) - { - return true; - } - } - - if (logIndex >= MAX_SYNC_HISTORY) - { - debug(LOG_NET, "Couldn't check gameTime: %" PRIu32 "", checkGameTime); - return false; // Couldn't check. May have dumped already, or MAX_SYNC_HISTORY isn't big enough compared to the maximum latency. - } - - size_t bufIndex = dumpLocalDebugSyncLog(logIndex); - if (syncDebugNumDumps < 2) - { - ++syncDebugNumDumps; - sendDebugSync(debugSyncTmpBuf, static_cast(bufIndex), syncDebugLog[logIndex].getGameTime()); - } - - // Backup correct CRC for checking against remaining players, even though we erased the logs (which were dumped already). - syncDebugExtraGameTime = syncDebugLog[logIndex].getGameTime(); - syncDebugExtraCrc = syncDebugLog[logIndex].getCrc(); - - // Finish erasing our version. - syncDebugLog[logIndex].clear(); - - return false; // Ouch. -} - const char *messageTypeToString(unsigned messageType_) { MESSAGE_TYPES messageType = (MESSAGE_TYPES)messageType_; // Cast to enum, so switch gives a warning if new message types are added without updating the switch. diff --git a/lib/netplay/netplay.h b/lib/netplay/netplay.h index ae68013bcf9..de77fadd087 100644 --- a/lib/netplay/netplay.h +++ b/lib/netplay/netplay.h @@ -31,6 +31,7 @@ #include "nettypes.h" #include "wzfile.h" #include "netlog.h" +#include "sync_debug.h" #include #include @@ -477,34 +478,6 @@ bool NETsetAsyncJoinApprovalResult(const std::string& uniqueJoinID, bool approve const char *messageTypeToString(unsigned messageType); -/// Sync debugging. Only prints anything, if different players would print different things. -#define syncDebug(...) do { _syncDebug(__FUNCTION__, __VA_ARGS__); } while(0) -#ifdef WZ_CC_MINGW -void _syncDebug(const char *function, const char *str, ...) WZ_DECL_FORMAT(__MINGW_PRINTF_FORMAT, 2, 3); -#else -void _syncDebug(const char *function, const char *str, ...) WZ_DECL_FORMAT(printf, 2, 3); -#endif - -/// Faster than syncDebug. Make sure that str is a format string that takes ints only. -void _syncDebugIntList(const char *function, const char *str, int *ints, size_t numInts); -#define syncDebugBacktrace() do { _syncDebugBacktrace(__FUNCTION__); } while(0) -void _syncDebugBacktrace(const char *function); ///< Adds a backtrace to syncDebug, if the platform supports it. Can be a bit slow, don't call way too often, unless desperate. -uint32_t syncDebugGetCrc(); ///< syncDebug() calls between uint32_t crc = syncDebugGetCrc(); and syncDebugSetCrc(crc); appear in synch debug logs, but without triggering a desynch if different. -void syncDebugSetCrc(uint32_t crc); ///< syncDebug() calls between uint32_t crc = syncDebugGetCrc(); and syncDebugSetCrc(crc); appear in synch debug logs, but without triggering a desynch if different. - -typedef uint16_t GameCrcType; // Truncate CRC of game state to 16 bits, to save a bit of bandwidth. -void resetSyncDebug(); ///< Resets the syncDebug, so syncDebug from a previous game doesn't cause a spurious desynch dump. -GameCrcType nextDebugSync(); ///< Returns a CRC corresponding to all syncDebug() calls since the last nextDebugSync() or resetSyncDebug() call. -bool checkDebugSync(uint32_t checkGameTime, GameCrcType checkCrc); ///< Dumps all syncDebug() calls from that gameTime, if the CRC doesn't match. - - -// Set whether verbose debug mode - outputting the current player's sync log for every single game tick - is enabled until a specific gameTime value -// WARNING: This may significantly impact performance *and* will fill up your drive with a lot of logs data! -// It is only intended to be used for debugging issues such as: replays desyncing when gameplay does not, etc. (And don't let the game run too long / set untilGameTime too high!) -void NET_setDebuggingModeVerboseOutputAllSyncLogs(uint32_t untilGameTime = 0); -void debugVerboseLogSyncIfNeeded(); - - /** * This structure provides read-only access to a player, and can be used to identify players uniquely. * diff --git a/lib/netplay/sync_debug.cpp b/lib/netplay/sync_debug.cpp new file mode 100644 index 00000000000..e62f82fb040 --- /dev/null +++ b/lib/netplay/sync_debug.cpp @@ -0,0 +1,578 @@ +/* + This file is part of Warzone 2100. + Copyright (C) 2024 Warzone 2100 Project + + Warzone 2100 is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation; either version 2 of the License, or + (at your option) any later version. + + Warzone 2100 is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with Warzone 2100; if not, write to the Free Software + Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +*/ + +#include "sync_debug.h" + +#include "lib/framework/wzglobal.h" +#include "lib/framework/crc.h" +#include "lib/framework/macros.h" +#include "lib/framework/string_ext.h" +#include "lib/framework/file.h" +#include "lib/framework/debug.h" +#include "lib/framework/physfs_ext.h" +#include "lib/gamelib/gtime.h" +#include "nettypes.h" +#include "netplay.h" +#include "netsocket.h" // solely to bring in `htonl` function + +#include + +#include +#include +#include +#include +#include +#include +#include + +#if defined(WZ_OS_LINUX) && defined(__GLIBC__) +#include // Nonfatal runtime backtraces. +#endif // defined(WZ_OS_LINUX) && defined(__GLIBC__) + +static uint32_t verboseDebugOutputAllSyncLogsUntilGameTime = 0; + +struct SyncDebugEntry +{ + char const* function; +}; + +struct SyncDebugString : public SyncDebugEntry +{ + void set(uint32_t& crc, char const* f, char const* string) + { + function = f; + crc = crcSum(crc, function, strlen(function) + 1); + crc = crcSum(crc, string, strlen(string) + 1); + } + int snprint(char* buf, size_t bufSize, char const*& string) const + { + int ret = snprintf(buf, bufSize, "[%s] %s\n", function, string); + string += strlen(string) + 1; + return ret; + } +}; + +struct SyncDebugValueChange : public SyncDebugEntry +{ + void set(uint32_t& crc, char const* f, char const* vn, int nv, int i) + { + function = f; + variableName = vn; + newValue = nv; + id = i; + uint32_t valueBytes = htonl(newValue); + crc = crcSum(crc, function, strlen(function) + 1); + crc = crcSum(crc, variableName, strlen(variableName) + 1); + crc = crcSum(crc, &valueBytes, 4); + } + int snprint(char* buf, size_t bufSize) const + { + if (id != -1) + { + return snprintf(buf, bufSize, "[%s] %d %s = %d\n", function, id, variableName, newValue); + } + return snprintf(buf, bufSize, "[%s] %s = %d\n", function, variableName, newValue); + } + + int newValue; + int id; + char const* variableName; +}; + +struct SyncDebugIntList : public SyncDebugEntry +{ + void set(uint32_t& crc, char const* f, char const* s, int const* ints, size_t num) + { + function = f; + string = s; + uint32_t valueBytes[40]; + numInts = std::min(num, ARRAY_SIZE(valueBytes)); + for (unsigned n = 0; n < numInts; ++n) + { + valueBytes[n] = htonl(ints[n]); + } + crc = crcSum(crc, valueBytes, 4 * numInts); + } + int snprint(char* buf, size_t bufSize, int const*& ints) const + { + size_t index = 0; + if (index < bufSize) + { + index += snprintf(buf + index, bufSize - index, "[%s] ", function); + } + if (index < bufSize) + { + switch (numInts) + { + case 0: index += snprintf(buf + index, bufSize - index, "%s", string); break; + case 1: index += snprintf(buf + index, bufSize - index, string, ints[0]); break; + case 2: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1]); break; + case 3: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2]); break; + case 4: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3]); break; + case 5: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4]); break; + case 6: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5]); break; + case 7: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6]); break; + case 8: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7]); break; + case 9: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8]); break; + case 10: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9]); break; + case 11: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10]); break; + case 12: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11]); break; + case 13: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12]); break; + case 14: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13]); break; + case 15: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14]); break; + case 16: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15]); break; + case 17: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16]); break; + case 18: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17]); break; + case 19: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18]); break; + case 20: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19]); break; + case 21: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20]); break; + case 22: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21]); break; + case 23: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22]); break; + case 24: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23]); break; + case 25: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24]); break; + case 26: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25]); break; + case 27: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26]); break; + case 28: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27]); break; + case 29: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28]); break; + case 30: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29]); break; + case 31: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30]); break; + case 32: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31]); break; + case 33: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32]); break; + case 34: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33]); break; + case 35: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34]); break; + case 36: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35]); break; + case 37: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36]); break; + case 38: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36], ints[37]); break; + case 39: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36], ints[37], ints[38]); break; + case 40: index += snprintf(buf + index, bufSize - index, string, ints[0], ints[1], ints[2], ints[3], ints[4], ints[5], ints[6], ints[7], ints[8], ints[9], ints[10], ints[11], ints[12], ints[13], ints[14], ints[15], ints[16], ints[17], ints[18], ints[19], ints[20], ints[21], ints[22], ints[23], ints[24], ints[25], ints[26], ints[27], ints[28], ints[29], ints[30], ints[31], ints[32], ints[33], ints[34], ints[35], ints[36], ints[37], ints[38], ints[39]); break; + default: index += snprintf(buf + index, bufSize - index, "Too many ints in intlist."); break; + } + } + if (index < bufSize) + { + index += snprintf(buf + index, bufSize - index, "\n"); + } + ints += numInts; + return index; + } + + char const* string; + unsigned numInts; +}; + +struct SyncDebugLog +{ + SyncDebugLog() : time(0), crc(0x00000000) {} + void clear() + { + log.clear(); + time = 0; + crc = 0x00000000; + //printf("Freeing %d strings, %d valueChanges, %d intLists, %d chars, %d ints\n", (int)strings.size(), (int)valueChanges.size(), (int)intLists.size(), (int)chars.size(), (int)ints.size()); + strings.clear(); + valueChanges.clear(); + intLists.clear(); + chars.clear(); + ints.clear(); + } + void string(char const* f, char const* s) + { + size_t offset = chars.size(); + chars.resize(chars.size() + strlen(s) + 1); + char* buf = &chars[offset]; + strcpy(buf, s); + + strings.resize(strings.size() + 1); + strings.back().set(crc, f, buf); + + log.push_back('s'); + } + void valueChange(char const* f, char const* vn, int nv, int i) + { + valueChanges.resize(valueChanges.size() + 1); + valueChanges.back().set(crc, f, vn, nv, i); + log.push_back('v'); + } + void intList(char const* f, char const* s, int* begin, size_t num) + { + size_t offset = ints.size(); + ints.resize(ints.size() + num); + int* buf = &ints[offset]; + std::copy(begin, begin + num, buf); + + intLists.resize(intLists.size() + 1); + intLists.back().set(crc, f, s, buf, num); + log.push_back('i'); + } + int snprint(char* buf, size_t bufSize) + { + SyncDebugString const* stringPtr = strings.empty() ? nullptr : &strings[0]; // .empty() check, since &strings[0] is undefined if strings is empty(), even if it's likely to work, anyway. + SyncDebugValueChange const* valueChangePtr = valueChanges.empty() ? nullptr : &valueChanges[0]; + SyncDebugIntList const* intListPtr = intLists.empty() ? nullptr : &intLists[0]; + char const* charPtr = chars.empty() ? nullptr : &chars[0]; + int const* intPtr = ints.empty() ? nullptr : &ints[0]; + + int index = 0; + for (size_t n = 0; n < log.size() && (size_t)index < bufSize; ++n) + { + char type = log[n]; + switch (type) + { + case 's': + index += stringPtr++->snprint(buf + index, bufSize - index, charPtr); + break; + case 'v': + index += valueChangePtr++->snprint(buf + index, bufSize - index); + break; + case 'i': + index += intListPtr++->snprint(buf + index, bufSize - index, intPtr); + break; + default: + abort(); + break; + } + } + return index; + } + uint32_t getGameTime() const + { + return time; + } + uint32_t getCrc() const + { + return ~crc; // Invert bits, since everyone else seems to do that with CRCs... + } + size_t getNumEntries() const + { + return log.size(); + } + void setGameTime(uint32_t newTime) + { + time = newTime; + } + void setCrc(uint32_t newCrc) + { + crc = ~newCrc; // Invert bits, since everyone else seems to do that with CRCs... + } + +private: + std::vector log; + uint32_t time; + uint32_t crc; + + std::vector strings; + std::vector valueChanges; + std::vector intLists; + + std::vector chars; + std::vector ints; + +private: + SyncDebugLog(SyncDebugLog const&)/* = delete*/; + SyncDebugLog& operator =(SyncDebugLog const&)/* = delete*/; +}; + +#define MAX_LEN_LOG_LINE 512 // From debug.c - no use printing something longer. +#define MAX_SYNC_HISTORY 12 + +static unsigned syncDebugNext = 0; +static SyncDebugLog syncDebugLog[MAX_SYNC_HISTORY]; +static uint32_t syncDebugExtraGameTime; +static uint32_t syncDebugExtraCrc; + +static uint32_t syncDebugNumDumps = 0; + +void _syncDebug(const char* function, const char* str, ...) +{ +#ifdef WZ_CC_MSVC + char const* f = function; while (*f != '\0') if (*f++ == ':') + { + function = f; // Strip "Class::" from "Class::myFunction". + } +#endif + + va_list ap; + char outputBuffer[MAX_LEN_LOG_LINE]; + + va_start(ap, str); + vssprintf(outputBuffer, str, ap); + va_end(ap); + + syncDebugLog[syncDebugNext].string(function, outputBuffer); +} + +void _syncDebugIntList(const char* function, const char* str, int* ints, size_t numInts) +{ +#ifdef WZ_CC_MSVC + char const* f = function; while (*f != '\0') if (*f++ == ':') + { + function = f; // Strip "Class::" from "Class::myFunction". + } +#endif + + syncDebugLog[syncDebugNext].intList(function, str, ints, numInts); +} + +void _syncDebugBacktrace(const char* function) +{ +#ifdef WZ_CC_MSVC + char const* f = function; while (*f != '\0') if (*f++ == ':') + { + function = f; // Strip "Class::" from "Class::myFunction". + } +#endif + + uint32_t backupCrc = syncDebugLog[syncDebugNext].getCrc(); // Ignore CRC changes from _syncDebug(), since identical backtraces can be printed differently. + +#if defined(WZ_OS_LINUX) && defined(__GLIBC__) + void* btv[20]; + unsigned num = backtrace(btv, sizeof(btv) / sizeof(*btv)); + char** btc = backtrace_symbols(btv, num); + unsigned i; + for (i = 1; i + 2 < num; ++i) // =1: Don't print "src/warzone2100(syncDebugBacktrace+0x16) [0x6312d1]". +2: Don't print last two lines of backtrace such as "/lib/libc.so.6(__libc_start_main+0xe6) [0x7f91e040ea26]", since the address varies (even with the same binary). + { + _syncDebug("BT", "%s", btc[i]); + } + free(btc); +#else + _syncDebug("BT", "Sorry, syncDebugBacktrace() not implemented on your system. Called from %s.", function); +#endif + + // Use CRC of something platform-independent, to avoid false positive desynchs. + backupCrc = ~crcSum(~backupCrc, function, strlen(function) + 1); + syncDebugLog[syncDebugNext].setCrc(backupCrc); +} + +uint32_t syncDebugGetCrc() +{ + return syncDebugLog[syncDebugNext].getCrc(); +} + +void syncDebugSetCrc(uint32_t crc) +{ + syncDebugLog[syncDebugNext].setCrc(crc); +} + +void resetSyncDebug() +{ + for (unsigned i = 0; i < MAX_SYNC_HISTORY; ++i) + { + syncDebugLog[i].clear(); + } + + syncDebugExtraGameTime = 0; + syncDebugExtraCrc = 0xFFFFFFFF; + + syncDebugNext = 0; + + syncDebugNumDumps = 0; +} + +GameCrcType nextDebugSync() +{ + uint32_t ret = syncDebugLog[syncDebugNext].getCrc(); + + // Save gameTime, so we know which CRC to compare with, later. + syncDebugLog[syncDebugNext].setGameTime(gameTime); + + // Go to next position, and free it ready for use. + syncDebugNext = (syncDebugNext + 1) % MAX_SYNC_HISTORY; + syncDebugLog[syncDebugNext].clear(); + + return (GameCrcType)ret; +} + +static void dumpDebugSyncImpl(uint8_t* buf, size_t bufLen, const char* fname) +{ + PHYSFS_file* fp = openSaveFile(fname); + if (!fp) + { + debug(LOG_ERROR, "Failed to open file for writing: %s", fname); + return; + } + ASSERT(bufLen <= static_cast(std::numeric_limits::max()), "bufLen (%zu) exceeds PHYSFS_uint32::max", bufLen); + WZ_PHYSFS_writeBytes(fp, buf, static_cast(bufLen)); + PHYSFS_close(fp); +} + +static void dumpDebugSync(uint8_t* buf, size_t bufLen, uint32_t time, unsigned player, bool syncError = true) +{ + char fname[100]; + ssprintf(fname, "logs/desync%u_p%u.txt", time, player); + + dumpDebugSyncImpl(buf, bufLen, fname); + + bool isSpectator = player < NetPlay.players.size() && NetPlay.players[player].isSpectator; + std::string typeDescription = (syncError) ? "sync error" : "sync log"; + std::string playerDescription = (isSpectator) ? "spectator" : "player"; + debug(LOG_ERROR, "Dumped %s %u's %s at gameTime %u to file: %s%s", playerDescription.c_str(), player, typeDescription.c_str(), time, WZ_PHYSFS_getRealDir_String(fname).c_str(), fname); +} + +static void sendDebugSync(uint8_t* buf, uint32_t bufLen, uint32_t time) +{ + // Save our own, before sending, so that if we have 2 clients running on the same computer, to guarantee that it is done saving before the other client saves on top. + dumpDebugSync(buf, bufLen, time, selectedPlayer); + + NETbeginEncode(NETbroadcastQueue(), NET_DEBUG_SYNC); + NETuint32_t(&time); + NETuint32_t(&bufLen); + NETbin(buf, bufLen); + NETend(); +} + +static uint8_t debugSyncTmpBuf[2000000]; + +static size_t dumpLocalDebugSyncLog(unsigned logIndex) +{ + size_t bufIndex = 0; + // Dump our version, and also erase it, so we only dump it at most once. + bufIndex += snprintf((char*)debugSyncTmpBuf + bufIndex, ARRAY_SIZE(debugSyncTmpBuf) - bufIndex, "===== BEGIN gameTime=%u, %zu entries, CRC 0x%08X =====\n", syncDebugLog[logIndex].getGameTime(), syncDebugLog[logIndex].getNumEntries(), syncDebugLog[logIndex].getCrc()); + bufIndex = MIN(bufIndex, ARRAY_SIZE(debugSyncTmpBuf)); // snprintf will not overflow debugSyncTmpBuf, but returns as much as it would have printed if possible. + bufIndex += syncDebugLog[logIndex].snprint((char*)debugSyncTmpBuf + bufIndex, ARRAY_SIZE(debugSyncTmpBuf) - bufIndex); + bufIndex = MIN(bufIndex, ARRAY_SIZE(debugSyncTmpBuf)); // snprintf will not overflow debugSyncTmpBuf, but returns as much as it would have printed if possible. + bufIndex += snprintf((char*)debugSyncTmpBuf + bufIndex, ARRAY_SIZE(debugSyncTmpBuf) - bufIndex, "===== END gameTime=%u, %zu entries, CRC 0x%08X =====\n", syncDebugLog[logIndex].getGameTime(), syncDebugLog[logIndex].getNumEntries(), syncDebugLog[logIndex].getCrc()); + bufIndex = MIN(bufIndex, ARRAY_SIZE(debugSyncTmpBuf)); // snprintf will not overflow debugSyncTmpBuf, but returns as much as it would have printed if possible. + + return bufIndex; +} + +static size_t dumpLocalDebugSyncLogByTime(uint32_t time) +{ + unsigned logIndex; + for (logIndex = 0; logIndex < MAX_SYNC_HISTORY; ++logIndex) + { + if (syncDebugLog[logIndex].getGameTime() == time) + { + break; // found the log index for this time + } + } + + if (logIndex >= MAX_SYNC_HISTORY) + { + // did not find it + debug(LOG_WARNING, "Couldn't find gameTime: %" PRIu32 " in history", time); + return 0; + } + + return dumpLocalDebugSyncLog(logIndex); +} + +void recvDebugSync(NETQUEUE queue) +{ + uint32_t time = 0; + uint32_t bufLen = 0; + + NETbeginDecode(queue, NET_DEBUG_SYNC); + NETuint32_t(&time); + NETuint32_t(&bufLen); + bufLen = MIN(bufLen, ARRAY_SIZE(debugSyncTmpBuf)); + NETbin(debugSyncTmpBuf, bufLen); + NETend(); + + dumpDebugSync(debugSyncTmpBuf, bufLen, time, queue.index); + + // Also dump the debug sync log for this local client (if possible) + bufLen = dumpLocalDebugSyncLogByTime(time); + if (bufLen > 0) + { + dumpDebugSync(debugSyncTmpBuf, bufLen, time, selectedPlayer, false); + } +} + +// Set whether verbose debug mode - outputting the current player's sync log for every single game tick - is enabled +// WARNING: This may significantly impact performance *and* will fill up your drive with a lot of logs data! +// It is only intended to be used for debugging issues such as: replays desyncing when gameplay does not, etc. (And don't let the game run too long!) +void NET_setDebuggingModeVerboseOutputAllSyncLogs(uint32_t untilGameTime) +{ + verboseDebugOutputAllSyncLogsUntilGameTime = untilGameTime; + if (verboseDebugOutputAllSyncLogsUntilGameTime) + { + debug(LOG_INFO, "WARNING: Verbose sync log output is enabled!"); + } +} + +void debugVerboseLogSyncIfNeeded() +{ + if (!verboseDebugOutputAllSyncLogsUntilGameTime || gameTime > verboseDebugOutputAllSyncLogsUntilGameTime) + { + return; + } + + auto bufLen = dumpLocalDebugSyncLogByTime(gameTime); + if (bufLen > 0) + { + char fname[100]; + ssprintf(fname, "logs/sync%u_p%u.txt", gameTime, selectedPlayer); + dumpDebugSyncImpl(debugSyncTmpBuf, bufLen, fname); + } +} + +bool checkDebugSync(uint32_t checkGameTime, GameCrcType checkCrc) +{ + if (checkGameTime == syncDebugLog[syncDebugNext].getGameTime()) // Can't happen - and syncDebugGameTime[] == 0, until just before sending the CRC, anyway. + { + debug(LOG_ERROR, "Huh? We aren't done yet..."); + return true; + } + + unsigned logIndex; + for (logIndex = 0; logIndex < MAX_SYNC_HISTORY; ++logIndex) + { + if (syncDebugLog[logIndex].getGameTime() == checkGameTime) + { + if ((GameCrcType)syncDebugLog[logIndex].getCrc() == checkCrc) + { + return true; // Check passed. (So far... There might still be more players to compare CRCs with.) + } + + debug(LOG_NET, "Non-matching crc for gameTime: %" PRIu32 "", checkGameTime); + break; // Check failed! + } + } + + if (logIndex >= MAX_SYNC_HISTORY && syncDebugExtraGameTime == checkGameTime) + { + if ((GameCrcType)syncDebugExtraCrc == checkCrc) + { + return true; + } + } + + if (logIndex >= MAX_SYNC_HISTORY) + { + debug(LOG_NET, "Couldn't check gameTime: %" PRIu32 "", checkGameTime); + return false; // Couldn't check. May have dumped already, or MAX_SYNC_HISTORY isn't big enough compared to the maximum latency. + } + + size_t bufIndex = dumpLocalDebugSyncLog(logIndex); + if (syncDebugNumDumps < 2) + { + ++syncDebugNumDumps; + sendDebugSync(debugSyncTmpBuf, static_cast(bufIndex), syncDebugLog[logIndex].getGameTime()); + } + + // Backup correct CRC for checking against remaining players, even though we erased the logs (which were dumped already). + syncDebugExtraGameTime = syncDebugLog[logIndex].getGameTime(); + syncDebugExtraCrc = syncDebugLog[logIndex].getCrc(); + + // Finish erasing our version. + syncDebugLog[logIndex].clear(); + + return false; // Ouch. +} diff --git a/lib/netplay/sync_debug.h b/lib/netplay/sync_debug.h new file mode 100644 index 00000000000..18746c14dcb --- /dev/null +++ b/lib/netplay/sync_debug.h @@ -0,0 +1,57 @@ +/* + This file is part of Warzone 2100. + Copyright (C) 2024 Warzone 2100 Project + + Warzone 2100 is free software; you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation; either version 2 of the License, or + (at your option) any later version. + + Warzone 2100 is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with Warzone 2100; if not, write to the Free Software + Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA +*/ + +#pragma once + +#include "lib/framework/wzglobal.h" +#include "lib/framework/frame.h" + +#include +#include + +/// Sync debugging. Only prints anything, if different players would print different things. +#define syncDebug(...) do { _syncDebug(__FUNCTION__, __VA_ARGS__); } while(0) +#ifdef WZ_CC_MINGW +void _syncDebug(const char* function, const char* str, ...) WZ_DECL_FORMAT(__MINGW_PRINTF_FORMAT, 2, 3); +#else +void _syncDebug(const char* function, const char* str, ...) WZ_DECL_FORMAT(printf, 2, 3); +#endif + +/// Faster than syncDebug. Make sure that str is a format string that takes ints only. +void _syncDebugIntList(const char* function, const char* str, int* ints, size_t numInts); +#define syncDebugBacktrace() do { _syncDebugBacktrace(__FUNCTION__); } while(0) +void _syncDebugBacktrace(const char* function); ///< Adds a backtrace to syncDebug, if the platform supports it. Can be a bit slow, don't call way too often, unless desperate. +uint32_t syncDebugGetCrc(); ///< syncDebug() calls between uint32_t crc = syncDebugGetCrc(); and syncDebugSetCrc(crc); appear in synch debug logs, but without triggering a desynch if different. +void syncDebugSetCrc(uint32_t crc); ///< syncDebug() calls between uint32_t crc = syncDebugGetCrc(); and syncDebugSetCrc(crc); appear in synch debug logs, but without triggering a desynch if different. + +typedef uint16_t GameCrcType; // Truncate CRC of game state to 16 bits, to save a bit of bandwidth. +void resetSyncDebug(); ///< Resets the syncDebug, so syncDebug from a previous game doesn't cause a spurious desynch dump. +GameCrcType nextDebugSync(); ///< Returns a CRC corresponding to all syncDebug() calls since the last nextDebugSync() or resetSyncDebug() call. +bool checkDebugSync(uint32_t checkGameTime, GameCrcType checkCrc); ///< Dumps all syncDebug() calls from that gameTime, if the CRC doesn't match. + + +// Set whether verbose debug mode - outputting the current player's sync log for every single game tick - is enabled until a specific gameTime value +// WARNING: This may significantly impact performance *and* will fill up your drive with a lot of logs data! +// It is only intended to be used for debugging issues such as: replays desyncing when gameplay does not, etc. (And don't let the game run too long / set untilGameTime too high!) +void NET_setDebuggingModeVerboseOutputAllSyncLogs(uint32_t untilGameTime = 0); +void debugVerboseLogSyncIfNeeded(); + +struct NETQUEUE; + +void recvDebugSync(NETQUEUE queue); From 30894f250a7b6027ab4f3295e24d07dc7250c22c Mon Sep 17 00:00:00 2001 From: Pavel Solodovnikov Date: Thu, 21 Mar 2024 19:52:45 +0300 Subject: [PATCH 9/9] netplay: make `upnp_status` variable static It's not used outside of `netplay.cpp`, so can be made `static`. Signed-off-by: Pavel Solodovnikov --- lib/netplay/netplay.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/netplay/netplay.cpp b/lib/netplay/netplay.cpp index ba8f64ba208..ffd732fc9b3 100644 --- a/lib/netplay/netplay.cpp +++ b/lib/netplay/netplay.cpp @@ -130,7 +130,7 @@ SYNC_COUNTER sync_counter; // keeps track on how well we are in sync // //////////////////////////////////////////////////////////////////////// // Types -std::atomic_int upnp_status; +static std::atomic_int upnp_status; struct Statistic {