From f0b0fcbb95de7d544bc23433adb7b8c41f154aee Mon Sep 17 00:00:00 2001 From: "Admiral H. Curtiss" Date: Wed, 16 Nov 2022 04:00:43 +0100 Subject: [PATCH] Netplay: Add more logging to save syncing. --- Source/Core/Core/NetPlayClient.cpp | 28 +++++++++++++++++++++++++ Source/Core/Core/NetPlayServer.cpp | 33 ++++++++++++++++++++++++++++-- 2 files changed, 59 insertions(+), 2 deletions(-) diff --git a/Source/Core/Core/NetPlayClient.cpp b/Source/Core/Core/NetPlayClient.cpp index 72b403e4d0..23f7e9fba3 100644 --- a/Source/Core/Core/NetPlayClient.cpp +++ b/Source/Core/Core/NetPlayClient.cpp @@ -980,6 +980,8 @@ void NetPlayClient::OnSyncSaveData(sf::Packet& packet) if (m_local_player->IsHost()) return; + INFO_LOG_FMT(NETPLAY, "Processing OnSyncSaveData sub id: {}", static_cast(sub_id)); + switch (sub_id) { case SyncSaveDataID::Notify: @@ -1013,6 +1015,8 @@ void NetPlayClient::OnSyncSaveDataNotify(sf::Packet& packet) packet >> m_sync_save_data_count; m_sync_save_data_success_count = 0; + INFO_LOG_FMT(NETPLAY, "Initializing wait for {} savegame chunks.", m_sync_save_data_count); + if (m_sync_save_data_count == 0) SyncSaveDataResponse(true); else @@ -1026,9 +1030,13 @@ void NetPlayClient::OnSyncSaveDataRaw(sf::Packet& packet) int size_override; packet >> is_slot_a >> region >> size_override; + INFO_LOG_FMT(NETPLAY, "Received raw memcard data for slot {}: region {}, size override {}.", + is_slot_a ? 'A' : 'B', region, size_override); + // This check is mainly intended to filter out characters which have special meanings in paths if (region != JAP_DIR && region != USA_DIR && region != EUR_DIR) { + WARN_LOG_FMT(NETPLAY, "Received invalid raw memory card region."); SyncSaveDataResponse(false); return; } @@ -1062,6 +1070,9 @@ void NetPlayClient::OnSyncSaveDataGCI(sf::Packet& packet) const std::string path = File::GetUserPath(D_GCUSER_IDX) + GC_MEMCARD_NETPLAY DIR_SEP + fmt::format("Card {}", is_slot_a ? 'A' : 'B'); + INFO_LOG_FMT(NETPLAY, "Received GCI memcard data for slot {}: {}, {} files.", + is_slot_a ? 'A' : 'B', path, file_count); + if ((File::Exists(path) && !File::DeleteDirRecursively(path + DIR_SEP)) || !File::CreateFullPath(path + DIR_SEP)) { @@ -1075,9 +1086,12 @@ void NetPlayClient::OnSyncSaveDataGCI(sf::Packet& packet) std::string file_name; packet >> file_name; + INFO_LOG_FMT(NETPLAY, "Received GCI: {}", file_name); + if (!Common::IsFileNameSafe(file_name) || !DecompressPacketIntoFile(packet, path + DIR_SEP + file_name)) { + WARN_LOG_FMT(NETPLAY, "Received invalid GCI."); SyncSaveDataResponse(false); return; } @@ -1118,6 +1132,8 @@ void NetPlayClient::OnSyncSaveDataWii(sf::Packet& packet) packet >> mii_data; if (mii_data) { + INFO_LOG_FMT(NETPLAY, "Received Mii data."); + auto buffer = DecompressPacketIntoBuffer(packet); temp_fs->CreateFullPath(IOS::PID_KERNEL, IOS::PID_KERNEL, "/shared2/menu/FaceLib/", 0, @@ -1136,6 +1152,7 @@ void NetPlayClient::OnSyncSaveDataWii(sf::Packet& packet) // Read the saves u32 save_count; packet >> save_count; + INFO_LOG_FMT(NETPLAY, "Received data for {} Wii saves.", save_count); for (u32 n = 0; n < save_count; n++) { u64 title_id = Common::PacketReadU64(packet); @@ -1147,7 +1164,12 @@ void NetPlayClient::OnSyncSaveDataWii(sf::Packet& packet) bool exists; packet >> exists; if (!exists) + { + INFO_LOG_FMT(NETPLAY, "No data for Wii save of title {:016x}.", title_id); continue; + } + + INFO_LOG_FMT(NETPLAY, "Received Wii save of title {:016x}.", title_id); // Header WiiSave::Header header; @@ -1186,6 +1208,9 @@ void NetPlayClient::OnSyncSaveDataWii(sf::Packet& packet) packet >> file.type; packet >> file.path; + INFO_LOG_FMT(NETPLAY, "Received Wii save data of type {} at {}", static_cast(file.type), + file.path); + if (file.type == WiiSave::Storage::SaveFile::Type::File) { auto buffer = DecompressPacketIntoBuffer(packet); @@ -1213,6 +1238,7 @@ void NetPlayClient::OnSyncSaveDataWii(sf::Packet& packet) packet >> has_redirected_save; if (has_redirected_save) { + INFO_LOG_FMT(NETPLAY, "Received redirected save."); if (!DecompressPacketIntoFolder(packet, redirect_path)) { PanicAlertFmtT("Failed to write redirected save."); @@ -1230,6 +1256,8 @@ void NetPlayClient::OnSyncSaveDataGBA(sf::Packet& packet) u8 slot; packet >> slot; + INFO_LOG_FMT(NETPLAY, "Received GBA save for slot {}.", slot); + const std::string path = fmt::format("{}{}{}.sav", File::GetUserPath(D_GBAUSER_IDX), GBA_SAVE_NETPLAY, slot + 1); if (File::Exists(path) && !File::Delete(path)) diff --git a/Source/Core/Core/NetPlayServer.cpp b/Source/Core/Core/NetPlayServer.cpp index 18076ada29..4bf98e8c44 100644 --- a/Source/Core/Core/NetPlayServer.cpp +++ b/Source/Core/Core/NetPlayServer.cpp @@ -1667,6 +1667,8 @@ std::optional NetPlayServer::CollectSaveSyncInfo() // called from ---GUI--- thread bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) { + INFO_LOG_FMT(NETPLAY, "Sending {} savegame chunks to clients.", sync_info.save_count); + // We're about to sync saves, so set m_saves_synced to false (waits to start game) m_saves_synced = false; @@ -1708,12 +1710,16 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) if (File::Exists(path)) { + INFO_LOG_FMT(NETPLAY, "Sending data of raw memcard {} in slot {}.", path, + is_slot_a ? 'A' : 'B'); if (!CompressFileIntoPacket(path, pac)) return false; } else { // No file, so we'll say the size is 0 + INFO_LOG_FMT(NETPLAY, "Sending empty marker for raw memcard {} in slot {}.", path, + is_slot_a ? 'A' : 'B'); pac << sf::Uint64{0}; } @@ -1736,17 +1742,25 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) std::vector files = GCMemcardDirectory::GetFileNamesForGameID(path + DIR_SEP, sync_info.game->GetGameID()); + INFO_LOG_FMT(NETPLAY, "Sending data of GCI memcard {} in slot {} ({} files).", path, + is_slot_a ? 'A' : 'B', files.size()); + pac << static_cast(files.size()); for (const std::string& file : files) { - pac << file.substr(file.find_last_of('/') + 1); + const std::string filename = file.substr(file.find_last_of('/') + 1); + INFO_LOG_FMT(NETPLAY, "Sending GCI {}.", filename); + pac << filename; if (!CompressFileIntoPacket(file, pac)) return false; } } else { + INFO_LOG_FMT(NETPLAY, "Sending empty marker for GCI memcard {} in slot {}.", path, + is_slot_a ? 'A' : 'B'); + pac << static_cast(0); } @@ -1764,17 +1778,19 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) // Shove the Mii data into the start the packet if (sync_info.mii_data) { + INFO_LOG_FMT(NETPLAY, "Sending Mii data."); pac << true; - if (!CompressBufferIntoPacket(*sync_info.mii_data, pac)) return false; } else { + INFO_LOG_FMT(NETPLAY, "Not sending Mii data."); pac << false; // no mii data } // Carry on with the save files + INFO_LOG_FMT(NETPLAY, "Sending {} Wii saves.", sync_info.wii_saves.size()); pac << static_cast(sync_info.wii_saves.size()); for (const auto& [title_id, storage] : sync_info.wii_saves) @@ -1787,8 +1803,12 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) const std::optional bk_header = storage->ReadBkHeader(); const std::optional> files = storage->ReadFiles(); if (!header || !bk_header || !files) + { + INFO_LOG_FMT(NETPLAY, "Wii save of title {:016x} is corrupted.", title_id); return false; + } + INFO_LOG_FMT(NETPLAY, "Sending Wii save of title {:016x}.", title_id); pac << true; // save exists // Header @@ -1813,6 +1833,9 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) // Files for (const WiiSave::Storage::SaveFile& file : *files) { + INFO_LOG_FMT(NETPLAY, "Sending Wii save data of type {} at {}", + static_cast(file.type), file.path); + pac << file.mode << file.attributes << file.type << file.path; if (file.type == WiiSave::Storage::SaveFile::Type::File) @@ -1825,18 +1848,22 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) } else { + INFO_LOG_FMT(NETPLAY, "No data for Wii save of title {:016x}.", title_id); pac << false; // save does not exist } } if (sync_info.redirected_save) { + INFO_LOG_FMT(NETPLAY, "Sending redirected save at {}.", + sync_info.redirected_save->m_target_path); pac << true; if (!CompressFolderIntoPacket(sync_info.redirected_save->m_target_path, pac)) return false; } else { + INFO_LOG_FMT(NETPLAY, "Not sending redirected save."); pac << false; // no redirected save } @@ -1859,12 +1886,14 @@ bool NetPlayServer::SyncSaveData(const SaveSyncInfo& sync_info) #endif if (File::Exists(path)) { + INFO_LOG_FMT(NETPLAY, "Sending data of GBA save at {} for slot {}.", path, i); if (!CompressFileIntoPacket(path, pac)) return false; } else { // No file, so we'll say the size is 0 + INFO_LOG_FMT(NETPLAY, "Sending empty marker for GBA save at {} for slot {}.", path, i); pac << sf::Uint64{0}; }