From f295e67b9f561a976983c6018e6bf3ef5bd61ef9 Mon Sep 17 00:00:00 2001 From: LP Date: Tue, 25 Nov 2025 11:07:49 +0800 Subject: [PATCH] Add multiplayer event logging --- CMake/Tests.cmake | 1 + Source/appfat.cpp | 3 +- Source/dvlnet/abstract_net.h | 4 +- Source/dvlnet/base.cpp | 8 ++-- Source/dvlnet/base.h | 4 +- Source/dvlnet/base_protocol.h | 4 +- Source/dvlnet/cdwrap.cpp | 4 +- Source/dvlnet/cdwrap.h | 4 +- Source/dvlnet/leaveinfo.hpp | 15 +++++++ Source/dvlnet/loopback.cpp | 4 +- Source/dvlnet/loopback.h | 4 +- Source/dvlnet/packet.h | 14 ++++-- Source/dvlnet/tcp_client.cpp | 2 +- Source/dvlnet/tcp_client.h | 2 +- Source/dvlnet/tcp_server.cpp | 2 +- Source/dvlnet/zerotier_native.cpp | 9 ++++ Source/main.cpp | 4 ++ Source/monster.cpp | 3 +- Source/msg.cpp | 20 ++++----- Source/msg.h | 5 ++- Source/multi.cpp | 75 ++++++++++++++++++++++++------- Source/multi.h | 8 +++- Source/platform/ctr/system.cpp | 2 + Source/storm/storm_net.cpp | 42 ++++++++++++++--- Source/storm/storm_net.hpp | 10 ++--- test/multi_logging_test.cpp | 28 ++++++++++++ 26 files changed, 217 insertions(+), 64 deletions(-) create mode 100644 Source/dvlnet/leaveinfo.hpp create mode 100644 test/multi_logging_test.cpp diff --git a/CMake/Tests.cmake b/CMake/Tests.cmake index 3498113ac..019e10b14 100644 --- a/CMake/Tests.cmake +++ b/CMake/Tests.cmake @@ -27,6 +27,7 @@ set(tests items_test math_test missiles_test + multi_logging_test pack_test player_test quests_test diff --git a/Source/appfat.cpp b/Source/appfat.cpp index 288e5237d..18a53e1ba 100644 --- a/Source/appfat.cpp +++ b/Source/appfat.cpp @@ -21,6 +21,7 @@ #include #include "diablo.h" +#include "dvlnet/leaveinfo.hpp" #include "multi.h" #include "storm/storm_net.hpp" #include "utils/language.h" @@ -50,7 +51,7 @@ void FreeDlg() CleanupThreadId = this_sdl_thread::get_id(); if (gbIsMultiplayer) { - if (SNetLeaveGame(3)) + if (SNetLeaveGame(leaveinfo_t::LEAVE_EXIT)) SDL_Delay(2000); } diff --git a/Source/dvlnet/abstract_net.h b/Source/dvlnet/abstract_net.h index e3d0aad4d..ea9fb8898 100644 --- a/Source/dvlnet/abstract_net.h +++ b/Source/dvlnet/abstract_net.h @@ -25,8 +25,8 @@ public: virtual void SNetGetProviderCaps(struct _SNETCAPS *caps) = 0; virtual bool SNetRegisterEventHandler(event_type evtype, SEVTHANDLER func) = 0; virtual bool SNetUnregisterEventHandler(event_type evtype) = 0; - virtual bool SNetLeaveGame(int type) = 0; - virtual bool SNetDropPlayer(int playerid, uint32_t flags) = 0; + virtual bool SNetLeaveGame(net::leaveinfo_t type) = 0; + virtual bool SNetDropPlayer(int playerid, net::leaveinfo_t flags) = 0; virtual bool SNetGetOwnerTurnsWaiting(uint32_t *turns) = 0; virtual bool SNetGetTurnsInTransit(uint32_t *turns) = 0; virtual void setup_gameinfo(buffer_t info) = 0; diff --git a/Source/dvlnet/base.cpp b/Source/dvlnet/base.cpp index c8ad3aecd..d892b7acc 100644 --- a/Source/dvlnet/base.cpp +++ b/Source/dvlnet/base.cpp @@ -469,11 +469,11 @@ bool base::SNetRegisterEventHandler(event_type evtype, SEVTHANDLER func) return true; } -bool base::SNetLeaveGame(int type) +bool base::SNetLeaveGame(net::leaveinfo_t type) { tl::expected, PacketError> pkt = pktfty->make_packet( - plr_self, PLR_BROADCAST, plr_self, static_cast(type)); + plr_self, PLR_BROADCAST, plr_self, type); if (!pkt.has_value()) { LogError("make_packet: {}", pkt.error().what()); return false; @@ -487,7 +487,7 @@ bool base::SNetLeaveGame(int type) return true; } -bool base::SNetDropPlayer(int playerid, uint32_t flags) +bool base::SNetDropPlayer(int playerid, net::leaveinfo_t flags) { const plr_t plr = static_cast(playerid); tl::expected, PacketError> pkt @@ -495,7 +495,7 @@ bool base::SNetDropPlayer(int playerid, uint32_t flags) plr_self, PLR_BROADCAST, plr, - static_cast(flags)); + flags); if (!pkt.has_value()) { LogError("make_packet: {}", pkt.error().what()); return false; diff --git a/Source/dvlnet/base.h b/Source/dvlnet/base.h index 8c9ce96bb..200d50dea 100644 --- a/Source/dvlnet/base.h +++ b/Source/dvlnet/base.h @@ -25,8 +25,8 @@ public: void SNetGetProviderCaps(struct _SNETCAPS *caps) override; bool SNetRegisterEventHandler(event_type evtype, SEVTHANDLER func) override; bool SNetUnregisterEventHandler(event_type evtype) override; - bool SNetLeaveGame(int type) override; - bool SNetDropPlayer(int playerid, uint32_t flags) override; + bool SNetLeaveGame(net::leaveinfo_t type) override; + bool SNetDropPlayer(int playerid, net::leaveinfo_t flags) override; bool SNetGetOwnerTurnsWaiting(uint32_t *turns) override; bool SNetGetTurnsInTransit(uint32_t *turns) override; diff --git a/Source/dvlnet/base_protocol.h b/Source/dvlnet/base_protocol.h index 9e51528be..3967186a4 100644 --- a/Source/dvlnet/base_protocol.h +++ b/Source/dvlnet/base_protocol.h @@ -31,7 +31,7 @@ public: tl::expected send(packet &pkt) override; void DisconnectNet(plr_t plr) override; - bool SNetLeaveGame(int type) override; + bool SNetLeaveGame(net::leaveinfo_t type) override; std::string make_default_gamename() override; bool send_info_request() override; @@ -576,7 +576,7 @@ DvlNetLatencies base_protocol

::get_latencies(uint8_t playerid) } template -bool base_protocol

::SNetLeaveGame(int type) +bool base_protocol

::SNetLeaveGame(net::leaveinfo_t type) { auto ret = base::SNetLeaveGame(type); recv(); diff --git a/Source/dvlnet/cdwrap.cpp b/Source/dvlnet/cdwrap.cpp index 00f048b50..f12492424 100644 --- a/Source/dvlnet/cdwrap.cpp +++ b/Source/dvlnet/cdwrap.cpp @@ -78,12 +78,12 @@ bool cdwrap::SNetRegisterEventHandler(event_type evtype, SEVTHANDLER func) return true; } -bool cdwrap::SNetLeaveGame(int type) +bool cdwrap::SNetLeaveGame(net::leaveinfo_t type) { return dvlnet_wrap->SNetLeaveGame(type); } -bool cdwrap::SNetDropPlayer(int playerid, uint32_t flags) +bool cdwrap::SNetDropPlayer(int playerid, net::leaveinfo_t flags) { return dvlnet_wrap->SNetDropPlayer(playerid, flags); } diff --git a/Source/dvlnet/cdwrap.h b/Source/dvlnet/cdwrap.h index 15f65fc82..597f9506b 100644 --- a/Source/dvlnet/cdwrap.h +++ b/Source/dvlnet/cdwrap.h @@ -41,8 +41,8 @@ public: void SNetGetProviderCaps(struct _SNETCAPS *caps) override; bool SNetRegisterEventHandler(event_type evtype, SEVTHANDLER func) override; bool SNetUnregisterEventHandler(event_type evtype) override; - bool SNetLeaveGame(int type) override; - bool SNetDropPlayer(int playerid, uint32_t flags) override; + bool SNetLeaveGame(net::leaveinfo_t type) override; + bool SNetDropPlayer(int playerid, net::leaveinfo_t flags) override; bool SNetGetOwnerTurnsWaiting(uint32_t *turns) override; bool SNetGetTurnsInTransit(uint32_t *turns) override; void setup_gameinfo(buffer_t info) override; diff --git a/Source/dvlnet/leaveinfo.hpp b/Source/dvlnet/leaveinfo.hpp new file mode 100644 index 000000000..a4bd6467c --- /dev/null +++ b/Source/dvlnet/leaveinfo.hpp @@ -0,0 +1,15 @@ +#pragma once + +#include + +namespace devilution { +namespace net { + +enum class leaveinfo_t : uint32_t { + LEAVE_EXIT = 3, + LEAVE_ENDING = 0x40000004, + LEAVE_DROP = 0x40000006, +}; + +} // namespace net +} // namespace devilution diff --git a/Source/dvlnet/loopback.cpp b/Source/dvlnet/loopback.cpp index 7685b2f96..8d0999881 100644 --- a/Source/dvlnet/loopback.cpp +++ b/Source/dvlnet/loopback.cpp @@ -85,13 +85,13 @@ bool loopback::SNetUnregisterEventHandler(event_type /*evtype*/) return true; } -bool loopback::SNetLeaveGame(int /*type*/) +bool loopback::SNetLeaveGame(net::leaveinfo_t /*type*/) { IsLoopback = false; return true; } -bool loopback::SNetDropPlayer(int /*playerid*/, uint32_t /*flags*/) +bool loopback::SNetDropPlayer(int /*playerid*/, net::leaveinfo_t /*flags*/) { return true; } diff --git a/Source/dvlnet/loopback.h b/Source/dvlnet/loopback.h index 4bf5d57dc..258400f68 100644 --- a/Source/dvlnet/loopback.h +++ b/Source/dvlnet/loopback.h @@ -26,8 +26,8 @@ public: void SNetGetProviderCaps(struct _SNETCAPS *caps) override; bool SNetRegisterEventHandler(event_type evtype, SEVTHANDLER func) override; bool SNetUnregisterEventHandler(event_type evtype) override; - bool SNetLeaveGame(int type) override; - bool SNetDropPlayer(int playerid, uint32_t flags) override; + bool SNetLeaveGame(net::leaveinfo_t type) override; + bool SNetDropPlayer(int playerid, net::leaveinfo_t flags) override; bool SNetGetOwnerTurnsWaiting(uint32_t *turns) override; bool SNetGetTurnsInTransit(uint32_t *turns) override; void setup_gameinfo(buffer_t info) override; diff --git a/Source/dvlnet/packet.h b/Source/dvlnet/packet.h index a8e675d27..7945ad530 100644 --- a/Source/dvlnet/packet.h +++ b/Source/dvlnet/packet.h @@ -15,6 +15,7 @@ #include "appfat.h" #include "dvlnet/abstract_net.h" +#include "dvlnet/leaveinfo.hpp" #include "utils/attributes.h" #include "utils/endian_read.hpp" #include "utils/endian_write.hpp" @@ -46,7 +47,6 @@ typedef uint8_t plr_t; typedef uint8_t seq_t; typedef uint32_t cookie_t; typedef uint32_t timestamp_t; -typedef uint32_t leaveinfo_t; #ifdef PACKET_ENCRYPTION typedef std::array key_t; #else @@ -404,11 +404,19 @@ tl::expected packet_out::process_element(const T &x) static_assert(sizeof(T) == 4 || sizeof(T) == 2 || sizeof(T) == 1, "Unsupported T"); if (sizeof(T) == 4) { unsigned char buf[4]; - WriteLE32(buf, x); + if constexpr (std::is_enum::value) { + WriteLE32(buf, static_cast>(x)); + } else { + WriteLE32(buf, x); + } decrypted_buffer.insert(decrypted_buffer.end(), buf, buf + 4); } else if (sizeof(T) == 2) { unsigned char buf[2]; - WriteLE16(buf, x); + if constexpr (std::is_enum::value) { + WriteLE16(buf, static_cast>(x)); + } else { + WriteLE16(buf, x); + } decrypted_buffer.insert(decrypted_buffer.end(), buf, buf + 2); } else if (sizeof(T) == 1) { decrypted_buffer.push_back(static_cast(x)); diff --git a/Source/dvlnet/tcp_client.cpp b/Source/dvlnet/tcp_client.cpp index 88a7ea796..01857a812 100644 --- a/Source/dvlnet/tcp_client.cpp +++ b/Source/dvlnet/tcp_client.cpp @@ -212,7 +212,7 @@ void tcp_client::DisconnectNet(plr_t plr) local_server->DisconnectNet(plr); } -bool tcp_client::SNetLeaveGame(int type) +bool tcp_client::SNetLeaveGame(net::leaveinfo_t type) { auto ret = base::SNetLeaveGame(type); poll(); diff --git a/Source/dvlnet/tcp_client.h b/Source/dvlnet/tcp_client.h index 3d959bdd1..2775a3a61 100644 --- a/Source/dvlnet/tcp_client.h +++ b/Source/dvlnet/tcp_client.h @@ -34,7 +34,7 @@ public: tl::expected send(packet &pkt) override; void DisconnectNet(plr_t plr) override; - bool SNetLeaveGame(int type) override; + bool SNetLeaveGame(net::leaveinfo_t type) override; ~tcp_client() override; diff --git a/Source/dvlnet/tcp_server.cpp b/Source/dvlnet/tcp_server.cpp index aaed1fee6..145b9d7be 100644 --- a/Source/dvlnet/tcp_server.cpp +++ b/Source/dvlnet/tcp_server.cpp @@ -267,7 +267,7 @@ void tcp_server::DropConnection(const scc &con) tl::expected, PacketError> pkt = pktfty.make_packet(PLR_MASTER, PLR_BROADCAST, - plr, static_cast(LEAVE_DROP)); + plr, leaveinfo_t::LEAVE_DROP); if (pkt.has_value()) { SendPacket(**pkt); } else { diff --git a/Source/dvlnet/zerotier_native.cpp b/Source/dvlnet/zerotier_native.cpp index 37061e477..07a10de01 100644 --- a/Source/dvlnet/zerotier_native.cpp +++ b/Source/dvlnet/zerotier_native.cpp @@ -25,7 +25,9 @@ #ifdef DVL_ZT_SYMLINK #include +#ifdef PACKET_ENCRYPTION #include +#endif #include "utils/str_cat.hpp" #include "utils/utf8.hpp" @@ -61,6 +63,7 @@ bool HasMultiByteChars(std::string_view path) return c_any_of(path, IsTrailUtf8CodeUnit); } +#ifdef PACKET_ENCRYPTION std::string ComputeAlternateFolderName(std::string_view path) { const size_t hashSize = crypto_generichash_BYTES; @@ -79,6 +82,12 @@ std::string ComputeAlternateFolderName(std::string_view path) } return std::string(buf, hashSize * 2); } +#else +std::string ComputeAlternateFolderName(std::string_view path) +{ + return {}; +} +#endif std::string ToZTCompliantPath(std::string_view configPath) { diff --git a/Source/main.cpp b/Source/main.cpp index d04a64954..492ba7919 100644 --- a/Source/main.cpp +++ b/Source/main.cpp @@ -38,15 +38,19 @@ extern "C" int main(int argc, char **argv) #ifdef __SWITCH__ switch_romfs_init(); switch_enable_network(); +#ifdef PACKET_ENCRYPTION randombytes_switchrandom_init(); #endif +#endif #ifdef __3DS__ ctr_sys_init(); #endif #ifdef __vita__ vita_enable_network(); +#ifdef PACKET_ENCRYPTION randombytes_vitarandom_init(); #endif +#endif #ifdef NXDK nxMountDrive('E', "\\Device\\Harddisk0\\Partition1\\"); #endif diff --git a/Source/monster.cpp b/Source/monster.cpp index 1e159330e..568ed36d6 100644 --- a/Source/monster.cpp +++ b/Source/monster.cpp @@ -39,6 +39,7 @@ #include "cursor.h" #include "dead.h" #include "diablo.h" +#include "dvlnet/leaveinfo.hpp" #include "effects.h" #include "engine/animationinfo.h" #include "engine/clx_sprite.hpp" @@ -3947,7 +3948,7 @@ void M_UpdateRelations(const Monster &monster) void DoEnding() { if (gbIsMultiplayer) { - SNetLeaveGame(LEAVE_ENDING); + SNetLeaveGame(leaveinfo_t::LEAVE_ENDING); } music_stop(); diff --git a/Source/msg.cpp b/Source/msg.cpp index 53a5e94c1..29fd9d930 100644 --- a/Source/msg.cpp +++ b/Source/msg.cpp @@ -444,7 +444,7 @@ void PrePacket() auto *cmd = reinterpret_cast(data); data += sizeof(*cmd); remainingBytes -= sizeof(*cmd); - multi_player_left(cmd->bPlr, Swap32LE(cmd->dwReason)); + multi_player_left(cmd->bPlr, static_cast(Swap32LE(cmd->dwReason))); continue; } @@ -780,7 +780,7 @@ void DeltaImportData(_cmd_id cmd, uint32_t recvOffset, int pnum) deltaSize = PkwareDecompress(&sgRecvBuf[1], static_cast(deltaSize), sizeof(sgRecvBuf) - 1); if (deltaSize == 0) { Log("PKWare decompression failure, dropping player {}", pnum); - SNetDropPlayer(pnum, LEAVE_DROP); + SNetDropPlayer(pnum, leaveinfo_t::LEAVE_DROP); return; } } @@ -800,13 +800,13 @@ void DeltaImportData(_cmd_id cmd, uint32_t recvOffset, int pnum) src = DeltaImportSpawnedMonsters(src, end, deltaLevel.spawnedMonsters); } else { Log("Received invalid deltas, dropping player {}", pnum); - SNetDropPlayer(pnum, LEAVE_DROP); + SNetDropPlayer(pnum, leaveinfo_t::LEAVE_DROP); return; } if (src == nullptr) { Log("Received invalid deltas, dropping player {}", pnum); - SNetDropPlayer(pnum, LEAVE_DROP); + SNetDropPlayer(pnum, leaveinfo_t::LEAVE_DROP); return; } @@ -995,7 +995,7 @@ size_t OnLevelData(const TCmdPlrInfoHdr &message, size_t maxCmdSize, const Playe if (sgdwRecvOffset + wBytes > sizeof(sgRecvBuf)) { Log("Received too many deltas, dropping player {}", player.getId()); - SNetDropPlayer(player.getId(), LEAVE_DROP); + SNetDropPlayer(player.getId(), leaveinfo_t::LEAVE_DROP); return wBytes + sizeof(message); } @@ -1115,7 +1115,7 @@ void DeltaPutItem(const TCmdPItem &message, Point position, const Player &player && item.def.dwSeed == message.def.dwSeed) { if (item.bCmd != TCmdPItem::DroppedItem) { Log("Suspicious floor item duplication, dropping player {}", player.getId()); - SNetDropPlayer(player.getId(), LEAVE_DROP); + SNetDropPlayer(player.getId(), leaveinfo_t::LEAVE_DROP); } return; } @@ -2694,11 +2694,11 @@ void ClearLastSentPlayerCmd() lastSentPlayerCmd = {}; } -void msg_send_drop_pkt(uint8_t pnum, int reason) +void msg_send_drop_pkt(uint8_t pnum, leaveinfo_t reason) { TFakeDropPlr cmd; - cmd.dwReason = Swap32LE(reason); + cmd.dwReason = Swap32LE(static_cast(reason)); cmd.bCmd = FAKE_CMD_DROPID; cmd.bPlr = pnum; BufferMessage(pnum, &cmd, sizeof(cmd)); @@ -3310,7 +3310,7 @@ bool ValidateCmdSize(size_t requiredCmdSize, size_t maxCmdSize, size_t playerId) return true; Log("Suspiciously small packet size, dropping player {}", playerId); - SNetDropPlayer(static_cast(playerId), LEAVE_DROP); + SNetDropPlayer(static_cast(playerId), leaveinfo_t::LEAVE_DROP); return false; } @@ -3480,7 +3480,7 @@ size_t ParseCmd(uint8_t pnum, const TCmd *pCmd, size_t maxCmdSize) if (pCmd->bCmd < CMD_DLEVEL || pCmd->bCmd > CMD_DLEVEL_END) { Log("Unrecognized network message {}, dropping player {}", static_cast(pCmd->bCmd), pnum); - SNetDropPlayer(pnum, LEAVE_DROP); + SNetDropPlayer(pnum, leaveinfo_t::LEAVE_DROP); return 0; } diff --git a/Source/msg.h b/Source/msg.h index 958669a70..e2ff12582 100644 --- a/Source/msg.h +++ b/Source/msg.h @@ -7,6 +7,7 @@ #include +#include "dvlnet/leaveinfo.hpp" #include "engine/point.hpp" #include "items.h" #include "monster.h" @@ -16,6 +17,8 @@ namespace devilution { +using net::leaveinfo_t; + #define MAX_SEND_STR_LEN 80 enum _cmd_id : uint8_t { @@ -716,7 +719,7 @@ extern int dwRecCount; void PrepareItemForNetwork(const Item &item, TItem &messageItem); void PrepareEarForNetwork(const Item &item, TEar &ear); void RecreateItem(const Player &player, const TItem &messageItem, Item &item); -void msg_send_drop_pkt(uint8_t pnum, int reason); +void msg_send_drop_pkt(uint8_t pnum, leaveinfo_t reason); bool msg_wait_resync(); void run_delta_info(); void DeltaExportData(uint8_t pnum); diff --git a/Source/multi.cpp b/Source/multi.cpp index c945db29c..63f1746fd 100644 --- a/Source/multi.cpp +++ b/Source/multi.cpp @@ -44,6 +44,7 @@ #include "utils/endian_swap.hpp" #include "utils/is_of.hpp" #include "utils/language.h" +#include "utils/log.hpp" #include "utils/str_cat.hpp" namespace devilution { @@ -59,7 +60,7 @@ bool sgbSendDeltaTbl[MAX_PLRS]; GameData sgGameInitInfo; bool gbSelectProvider; int sglTimeoutStart; -uint32_t sgdwPlayerLeftReasonTbl[MAX_PLRS]; +leaveinfo_t sgdwPlayerLeftReasonTbl[MAX_PLRS]; uint32_t sgdwGameLoops; /** * Specifies the maximum number of players in a game, where 1 @@ -216,7 +217,7 @@ void CheckPlayerInfoTimeouts() // Time the player out after 15 seconds // if we do not receive valid player info if (SDL_GetTicks() - timerStart >= 15000) { - SNetDropPlayer(i, LEAVE_DROP); + SNetDropPlayer(i, leaveinfo_t::LEAVE_DROP); timerStart = 0; } } @@ -288,16 +289,27 @@ void PlayerLeftMsg(Player &player, bool left) RemoveEnemyReferences(player); RemovePlrMissiles(player); if (left) { + const leaveinfo_t leaveReason = sgdwPlayerLeftReasonTbl[player.getId()]; + const std::string reasonDescription = DescribeLeaveReason(leaveReason); std::string_view pszFmt = _("Player '{:s}' just left the game"); - switch (sgdwPlayerLeftReasonTbl[player.getId()]) { - case LEAVE_ENDING: + switch (leaveReason) { + case leaveinfo_t::LEAVE_EXIT: + break; + case leaveinfo_t::LEAVE_ENDING: pszFmt = _("Player '{:s}' killed Diablo and left the game!"); gbSomebodyWonGameKludge = true; break; - case LEAVE_DROP: + case leaveinfo_t::LEAVE_DROP: pszFmt = _("Player '{:s}' dropped due to timeout"); break; } + if (!IsLoopback) { + const uint8_t remainingPlayers = gbActivePlayers > 0 ? gbActivePlayers - 1 : 0; + if (player._pName[0] != '\0') + LogInfo("Player '{}' left the {} game ({}, {}/{} players)", player._pName, ConnectionNames[provider], reasonDescription, remainingPlayers, MAX_PLRS); + else + LogInfo("Player left the {} game ({}, {}/{} players)", ConnectionNames[provider], reasonDescription, remainingPlayers, MAX_PLRS); + } EventPlrMsg(fmt::format(fmt::runtime(pszFmt), player._pName)); } player.plractive = false; @@ -316,7 +328,7 @@ void ClearPlayerLeftState() PlayerLeftMsg(Players[i], true); sgbPlayerLeftGameTbl[i] = false; - sgdwPlayerLeftReasonTbl[i] = 0; + sgdwPlayerLeftReasonTbl[i] = static_cast(0); } } } @@ -325,7 +337,7 @@ void CheckDropPlayer() { for (uint8_t i = 0; i < Players.size(); i++) { if ((player_state[i] & PS_ACTIVE) == 0 && (player_state[i] & PS_CONNECTED) != 0) { - SNetDropPlayer(i, LEAVE_DROP); + SNetDropPlayer(i, leaveinfo_t::LEAVE_DROP); } } } @@ -422,13 +434,14 @@ void HandleEvents(_SNETEVENT *pEvt) sgbPlayerLeftGameTbl[playerId] = true; sgbPlayerTurnBitTbl[playerId] = false; - int32_t leftReason = 0; - if (pEvt->data != nullptr && pEvt->databytes >= sizeof(leftReason)) { - std::memcpy(&leftReason, pEvt->data, sizeof(leftReason)); - leftReason = Swap32LE(leftReason); + uint32_t leftReasonRaw = 0; + if (pEvt->data != nullptr && pEvt->databytes >= sizeof(leftReasonRaw)) { + std::memcpy(&leftReasonRaw, pEvt->data, sizeof(leftReasonRaw)); + leftReasonRaw = Swap32LE(leftReasonRaw); } + leaveinfo_t leftReason = static_cast(leftReasonRaw); sgdwPlayerLeftReasonTbl[playerId] = leftReason; - if (leftReason == LEAVE_ENDING) + if (leftReason == leaveinfo_t::LEAVE_ENDING) gbSomebodyWonGameKludge = true; sgbSendDeltaTbl[playerId] = false; @@ -520,6 +533,26 @@ bool InitMulti(GameData *gameData) } // namespace +DVL_API_FOR_TEST std::string DescribeLeaveReason(leaveinfo_t leaveReason) +{ + switch (leaveReason) { + case leaveinfo_t::LEAVE_EXIT: + return "normal exit"; + case leaveinfo_t::LEAVE_ENDING: + return "Diablo defeated"; + case leaveinfo_t::LEAVE_DROP: + return "connection timeout"; + default: + return fmt::format("code 0x{:08X}", static_cast(leaveReason)); + } +} + +std::string FormatGameSeed(const uint32_t gameSeed[4]) +{ + return fmt::format("{:08X}{:08X}{:08X}{:08X}", + gameSeed[0], gameSeed[1], gameSeed[2], gameSeed[3]); +} + void InitGameInfo() { const xoshiro128plusplus gameGenerator = ReserveSeedSequence(); @@ -597,7 +630,7 @@ void multi_msg_countdown() } } -void multi_player_left(uint8_t pnum, int reason) +void multi_player_left(uint8_t pnum, leaveinfo_t reason) { sgbPlayerLeftGameTbl[pnum] = true; sgdwPlayerLeftReasonTbl[pnum] = reason; @@ -769,7 +802,7 @@ void NetClose() nthread_cleanup(); tmsg_cleanup(); UnregisterNetEventHandlers(); - SNetLeaveGame(3); + SNetLeaveGame(leaveinfo_t::LEAVE_EXIT); if (gbIsMultiplayer) SDL_Delay(2000); if (!demo::IsRunning()) { @@ -843,6 +876,16 @@ bool NetInit(bool bSinglePlayer) AddMessageToChatLog(_("New Game"), nullptr, UiFlags::ColorRed); AddMessageToChatLog(fmt::format(fmt::runtime(_("Player '{:s}' (level {:d}) just joined the game")), myPlayer._pName, myPlayer.getCharacterLevel())); + // Log join message with seed for joining players (creator already logged it in SNetCreateGame) + if (gbIsMultiplayer && !IsLoopback && MyPlayerId != 0) { + std::string upperGameName = GameName; + std::transform(upperGameName.begin(), upperGameName.end(), upperGameName.begin(), ::toupper); + const char *privacy = PublicGame ? "public" : "private"; + LogInfo("Joined {} {} multiplayer game '{}' (player id: {}, seed: {})", + privacy, ConnectionNames[provider], upperGameName, MyPlayerId, + FormatGameSeed(sgGameInitInfo.gameSeed)); + } + return true; } @@ -877,7 +920,7 @@ void recv_plrinfo(Player &player, const TCmdPlrInfoHdr &header, bool recv) PlayerLeftMsg(player, false); if (!UnPackNetPlayer(packedPlayer, player)) { player = {}; - SNetDropPlayer(pnum, LEAVE_DROP); + SNetDropPlayer(pnum, leaveinfo_t::LEAVE_DROP); return; } @@ -892,6 +935,8 @@ void recv_plrinfo(Player &player, const TCmdPlrInfoHdr &header, bool recv) std::string_view szEvent; if (sgbPlayerTurnBitTbl[pnum]) { szEvent = _("Player '{:s}' (level {:d}) just joined the game"); + if (!IsLoopback) + LogInfo("Player '{}' joined the {} game (level {}, {}/{} players)", player._pName, ConnectionNames[provider], player.getCharacterLevel(), gbActivePlayers, MAX_PLRS); } else { szEvent = _("Player '{:s}' (level {:d}) is already in the game"); } diff --git a/Source/multi.h b/Source/multi.h index 8dfae3b87..df3ec90ea 100644 --- a/Source/multi.h +++ b/Source/multi.h @@ -9,11 +9,14 @@ #include #include +#include "dvlnet/leaveinfo.hpp" #include "msg.h" #include "utils/attributes.h" namespace devilution { +using net::leaveinfo_t; + // Defined in player.h, forward declared here to allow for functions which operate in the context of a player. struct Player; @@ -63,12 +66,15 @@ extern uint8_t gbDeltaSender; extern uint32_t player_state[MAX_PLRS]; extern bool IsLoopback; +DVL_API_FOR_TEST std::string DescribeLeaveReason(leaveinfo_t leaveReason); +std::string FormatGameSeed(const uint32_t gameSeed[4]); + void InitGameInfo(); void NetSendLoPri(uint8_t playerId, const std::byte *data, size_t size); void NetSendHiPri(uint8_t playerId, const std::byte *data, size_t size); void multi_send_msg_packet(uint32_t pmask, const std::byte *data, size_t size); void multi_msg_countdown(); -void multi_player_left(uint8_t pnum, int reason); +void multi_player_left(uint8_t pnum, leaveinfo_t reason); void multi_net_ping(); /** diff --git a/Source/platform/ctr/system.cpp b/Source/platform/ctr/system.cpp index 2bba1e960..575407419 100644 --- a/Source/platform/ctr/system.cpp +++ b/Source/platform/ctr/system.cpp @@ -114,9 +114,11 @@ void ctr_sys_init() n3ds_socInit(); atexit([]() { n3ds_socExit(); }); +#ifdef PACKET_ENCRYPTION randombytes_ctrrandom_init(); atexit([]() { if (psGetSessionHandle()) psExit(); }); +#endif } diff --git a/Source/storm/storm_net.cpp b/Source/storm/storm_net.cpp index 40862e9c1..8625ba3a2 100644 --- a/Source/storm/storm_net.cpp +++ b/Source/storm/storm_net.cpp @@ -1,5 +1,6 @@ #include "storm/storm_net.hpp" +#include #include #include @@ -17,6 +18,7 @@ #include "menu.h" #include "multi.h" #include "options.h" +#include "utils/log.hpp" #include "utils/stubs.h" #include "utils/utf8.hpp" @@ -100,7 +102,7 @@ bool SNetDestroy() return true; } -bool SNetDropPlayer(uint8_t playerid, uint32_t flags) +bool SNetDropPlayer(uint8_t playerid, leaveinfo_t flags) { #ifndef NONET std::lock_guard lg(storm_net_mutex); @@ -108,13 +110,20 @@ bool SNetDropPlayer(uint8_t playerid, uint32_t flags) return dvlnet_inst->SNetDropPlayer(playerid, flags); } -bool SNetLeaveGame(int type) +bool SNetLeaveGame(leaveinfo_t type) { #ifndef NONET std::lock_guard lg(storm_net_mutex); #endif if (dvlnet_inst == nullptr) return true; + if (!IsLoopback) { + std::string upperGameName = GameName; + std::transform(upperGameName.begin(), upperGameName.end(), upperGameName.begin(), ::toupper); + const std::string reasonDescription = DescribeLeaveReason(type); + LogInfo("Leaving {} multiplayer game '{}' (reason: {})", + ConnectionNames[provider], upperGameName, reasonDescription); + } return dvlnet_inst->SNetLeaveGame(type); } @@ -156,8 +165,25 @@ bool SNetCreateGame(const char *pszGameName, const char *pszGamePassword, char * DvlNet_SetPassword(pszGamePassword); else DvlNet_ClearPassword(); - *playerID = dvlnet_inst->create(pszGameName); - return *playerID != -1; + const int createdPlayerId = dvlnet_inst->create(pszGameName); + if (createdPlayerId == -1) + return false; + *playerID = createdPlayerId; + if (!IsLoopback) { + std::string upperGameName = GameName; + std::transform(upperGameName.begin(), upperGameName.end(), upperGameName.begin(), ::toupper); + const char *privacy = GameIsPublic ? "public" : "private"; + if (gameTemplateData != nullptr && gameTemplateSize >= static_cast(sizeof(GameData))) { + const GameData *gameData = reinterpret_cast(gameTemplateData); + LogInfo("Created {} {} multiplayer game '{}' (player id: {}, seed: {})", + privacy, ConnectionNames[provider], upperGameName, createdPlayerId, + FormatGameSeed(gameData->gameSeed)); + } else { + LogInfo("Created {} {} multiplayer game '{}' (player id: {}, seed unavailable)", + privacy, ConnectionNames[provider], upperGameName, createdPlayerId); + } + } + return true; } bool SNetJoinGame(char *pszGameName, char *pszGamePassword, int *playerID) @@ -171,8 +197,12 @@ bool SNetJoinGame(char *pszGameName, char *pszGamePassword, int *playerID) DvlNet_SetPassword(pszGamePassword); else DvlNet_ClearPassword(); - *playerID = dvlnet_inst->join(pszGameName); - return *playerID != -1; + const int joinedPlayerId = dvlnet_inst->join(pszGameName); + if (joinedPlayerId == -1) + return false; + *playerID = joinedPlayerId; + // Join message with seed will be logged in NetInit after game data is synchronized + return true; } /** diff --git a/Source/storm/storm_net.hpp b/Source/storm/storm_net.hpp index c4c7b1df3..dd91f50cb 100644 --- a/Source/storm/storm_net.hpp +++ b/Source/storm/storm_net.hpp @@ -10,6 +10,8 @@ namespace devilution { +using net::leaveinfo_t; + enum conn_type : uint8_t { SELCONN_ZT, SELCONN_TCP, @@ -23,6 +25,7 @@ enum event_type : uint8_t { }; extern const char *ConnectionNames[]; +extern int provider; struct _SNETCAPS { uint32_t size; @@ -53,9 +56,6 @@ struct DvlNetLatencies { #define PS_TURN_ARRIVED 0x20000 #define PS_ACTIVE 0x40000 -#define LEAVE_ENDING 0x40000004 -#define LEAVE_DROP 0x40000006 - bool SNetCreateGame(const char *pszGameName, const char *pszGamePassword, char *GameTemplateData, int GameTemplateSize, int *playerID); bool SNetDestroy(); @@ -68,7 +68,7 @@ bool SNetDestroy(); * * Returns true if the function was called successfully and false otherwise. */ -bool SNetDropPlayer(uint8_t playerid, uint32_t flags); +bool SNetDropPlayer(uint8_t playerid, leaveinfo_t flags); /* SNetGetTurnsInTransit @ 115 * @@ -92,7 +92,7 @@ bool SNetJoinGame(char *gameName, char *gamePassword, int *playerid); * * Returns true if the function was called successfully and false otherwise. */ -bool SNetLeaveGame(int type); +bool SNetLeaveGame(leaveinfo_t type); bool SNetReceiveMessage(uint8_t *senderplayerid, void **data, size_t *databytes); bool SNetReceiveTurns(int arraysize, char **arraydata, size_t *arraydatabytes, uint32_t *arrayplayerstatus); diff --git a/test/multi_logging_test.cpp b/test/multi_logging_test.cpp new file mode 100644 index 000000000..1b3c04a4a --- /dev/null +++ b/test/multi_logging_test.cpp @@ -0,0 +1,28 @@ +#include + +#include "multi.h" + +namespace devilution { + +TEST(MultiplayerLogging, NormalExitReason) +{ + EXPECT_EQ("normal exit", DescribeLeaveReason(net::leaveinfo_t::LEAVE_EXIT)); +} + +TEST(MultiplayerLogging, DiabloEndingReason) +{ + EXPECT_EQ("Diablo defeated", DescribeLeaveReason(net::leaveinfo_t::LEAVE_ENDING)); +} + +TEST(MultiplayerLogging, DropReason) +{ + EXPECT_EQ("connection timeout", DescribeLeaveReason(net::leaveinfo_t::LEAVE_DROP)); +} + +TEST(MultiplayerLogging, CustomReasonCode) +{ + constexpr net::leaveinfo_t CustomCode = static_cast(0xDEADBEEF); + EXPECT_EQ("code 0xDEADBEEF", DescribeLeaveReason(CustomCode)); +} + +} // namespace devilution