/* Copyright (C) 2015 Wildfire Games. * This file is part of 0 A.D. * * 0 A.D. 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. * * 0 A.D. 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 0 A.D. If not, see . */ #include "precompiled.h" #include "NetTurnManager.h" #include "NetMessage.h" #include "network/NetServer.h" #include "network/NetClient.h" #include "network/NetMessage.h" #include "gui/GUIManager.h" #include "maths/MathUtil.h" #include "ps/CLogger.h" #include "ps/Profile.h" #include "ps/Pyrogenesis.h" #include "ps/Replay.h" #include "ps/SavedGame.h" #include "scriptinterface/ScriptInterface.h" #include "simulation2/Simulation2.h" #include #include #include static const int DEFAULT_TURN_LENGTH_MP = 500; static const int DEFAULT_TURN_LENGTH_SP = 200; static const int COMMAND_DELAY = 2; #if 0 #define NETTURN_LOG(args) debug_printf args #else #define NETTURN_LOG(args) #endif static std::string Hexify(const std::string& s) { std::stringstream str; str << std::hex; for (size_t i = 0; i < s.size(); ++i) str << std::setfill('0') << std::setw(2) << (int)(unsigned char)s[i]; return str.str(); } CNetTurnManager::CNetTurnManager(CSimulation2& simulation, u32 defaultTurnLength, int clientId, IReplayLogger& replay) : m_Simulation2(simulation), m_CurrentTurn(0), m_ReadyTurn(1), m_TurnLength(defaultTurnLength), m_DeltaSimTime(0), m_PlayerId(-1), m_ClientId(clientId), m_HasSyncError(false), m_Replay(replay), m_TimeWarpNumTurns(0) { // When we are on turn n, we schedule new commands for n+2. // We know that all other clients have finished scheduling commands for n (else we couldn't have got here). // We know we have not yet finished scheduling commands for n+2. // Hence other clients can be on turn n-1, n, n+1, and no other. // So they can be sending us commands scheduled for n+1, n+2, n+3. // So we need a 3-element buffer: m_QueuedCommands.resize(COMMAND_DELAY + 1); } void CNetTurnManager::ResetState(u32 newCurrentTurn, u32 newReadyTurn) { m_CurrentTurn = newCurrentTurn; m_ReadyTurn = newReadyTurn; m_DeltaSimTime = 0; size_t queuedCommandsSize = m_QueuedCommands.size(); m_QueuedCommands.clear(); m_QueuedCommands.resize(queuedCommandsSize); } void CNetTurnManager::SetPlayerID(int playerId) { m_PlayerId = playerId; } bool CNetTurnManager::WillUpdate(float simFrameLength) { // Keep this in sync with the return value of Update() if (m_DeltaSimTime + simFrameLength < 0) return false; if (m_ReadyTurn <= m_CurrentTurn) return false; return true; } bool CNetTurnManager::Update(float simFrameLength, size_t maxTurns) { m_DeltaSimTime += simFrameLength; // If we haven't reached the next turn yet, do nothing if (m_DeltaSimTime < 0) return false; NETTURN_LOG((L"Update current=%d ready=%d\n", m_CurrentTurn, m_ReadyTurn)); // Check that the next turn is ready for execution if (m_ReadyTurn <= m_CurrentTurn) { // Oops, we wanted to start the next turn but it's not ready yet - // there must be too much network lag. // TODO: complain to the user. // TODO: send feedback to the server to increase the turn length. // Reset the next-turn timer to 0 so we try again next update but // so we don't rush to catch up in subsequent turns. // TODO: we should do clever rate adjustment instead of just pausing like this. m_DeltaSimTime = 0; return false; } maxTurns = std::max((size_t)1, maxTurns); // always do at least one turn for (size_t i = 0; i < maxTurns; ++i) { // Check that we've reached the i'th next turn if (m_DeltaSimTime < 0) break; // Check that the i'th next turn is still ready if (m_ReadyTurn <= m_CurrentTurn) break; NotifyFinishedOwnCommands(m_CurrentTurn + COMMAND_DELAY); m_CurrentTurn += 1; // increase the turn number now, so Update can send new commands for a subsequent turn // Clean up any destroyed entities since the last turn (e.g. placement previews // or rally point flags generated by the GUI). (Must do this before the time warp // serialization.) m_Simulation2.FlushDestroyedEntities(); // Save the current state for rewinding, if enabled if (m_TimeWarpNumTurns && (m_CurrentTurn % m_TimeWarpNumTurns) == 0) { PROFILE3("time warp serialization"); std::stringstream stream; m_Simulation2.SerializeState(stream); m_TimeWarpStates.push_back(stream.str()); } // Put all the client commands into a single list, in a globally consistent order std::vector commands; for (std::map >::iterator it = m_QueuedCommands[0].begin(); it != m_QueuedCommands[0].end(); ++it) { commands.insert(commands.end(), std::make_move_iterator(it->second.begin()), std::make_move_iterator(it->second.end())); } m_QueuedCommands.pop_front(); m_QueuedCommands.resize(m_QueuedCommands.size() + 1); m_Replay.Turn(m_CurrentTurn-1, m_TurnLength, commands); NETTURN_LOG((L"Running %d cmds\n", commands.size())); m_Simulation2.Update(m_TurnLength, commands); NotifyFinishedUpdate(m_CurrentTurn); // Set the time for the next turn update m_DeltaSimTime -= m_TurnLength / 1000.f; } return true; } bool CNetTurnManager::UpdateFastForward() { m_DeltaSimTime = 0; NETTURN_LOG((L"UpdateFastForward current=%d ready=%d\n", m_CurrentTurn, m_ReadyTurn)); // Check that the next turn is ready for execution if (m_ReadyTurn <= m_CurrentTurn) return false; while (m_ReadyTurn > m_CurrentTurn) { // TODO: It would be nice to remove some of the duplication with Update() // (This is similar but doesn't call any Notify functions or update DeltaTime, // it just updates the simulation state) m_CurrentTurn += 1; m_Simulation2.FlushDestroyedEntities(); // Put all the client commands into a single list, in a globally consistent order std::vector commands; for (std::map >::iterator it = m_QueuedCommands[0].begin(); it != m_QueuedCommands[0].end(); ++it) { commands.insert(commands.end(), std::make_move_iterator(it->second.begin()), std::make_move_iterator(it->second.end())); } m_QueuedCommands.pop_front(); m_QueuedCommands.resize(m_QueuedCommands.size() + 1); m_Replay.Turn(m_CurrentTurn-1, m_TurnLength, commands); NETTURN_LOG((L"Running %d cmds\n", commands.size())); m_Simulation2.Update(m_TurnLength, commands); } return true; } void CNetTurnManager::OnSyncError(u32 turn, const CStr& expectedHash, std::vector& playerNames) { NETTURN_LOG((L"OnSyncError(%d, %hs)\n", turn, Hexify(expectedHash).c_str())); // Only complain the first time if (m_HasSyncError) return; bool quick = !TurnNeedsFullHash(turn); std::string hash; ENSURE(m_Simulation2.ComputeStateHash(hash, quick)); OsPath path = psLogDir()/"oos_dump.txt"; std::ofstream file (OsString(path).c_str(), std::ofstream::out | std::ofstream::trunc); m_Simulation2.DumpDebugState(file); file.close(); hash = Hexify(hash); const std::string& expectedHashHex = Hexify(expectedHash); DisplayOOSError(turn, hash, expectedHashHex, false, &playerNames, &path); } void CNetTurnManager::DisplayOOSError(u32 turn, const CStr& hash, const CStr& expectedHash, bool isReplay, std::vector* playerNames = NULL, OsPath* path = NULL) { m_HasSyncError = true; std::stringstream msg; msg << "Out of sync on turn " << turn; if (playerNames) for (size_t i = 0; i < playerNames->size(); ++i) msg << (i == 0 ? "\nPlayers: " : ", ") << utf8_from_wstring((*playerNames)[i].m_Name); if (isReplay) msg << "\n\n" << "The current game state is different from the original game state."; else msg << "\n\n" << "Your game state is " << (expectedHash == hash ? "identical to" : "different from") << " the hosts game state."; if (path) msg << "\n\n" << "Dumping current state to " << CStr(path->string8()).EscapeToPrintableASCII(); LOGERROR("%s", msg.str()); if (g_GUI) g_GUI->DisplayMessageBox(600, 350, L"Sync error", wstring_from_utf8(msg.str())); } void CNetTurnManager::Interpolate(float simFrameLength, float realFrameLength) { // TODO: using m_TurnLength might be a bit dodgy when length changes - maybe // we need to save the previous turn length? float offset = clamp(m_DeltaSimTime / (m_TurnLength / 1000.f) + 1.0, 0.0, 1.0); m_Simulation2.Interpolate(simFrameLength, offset, realFrameLength); } void CNetTurnManager::AddCommand(int client, int player, JS::HandleValue data, u32 turn) { NETTURN_LOG((L"AddCommand(client=%d player=%d turn=%d)\n", client, player, turn)); if (!(m_CurrentTurn < turn && turn <= m_CurrentTurn + COMMAND_DELAY + 1)) { debug_warn(L"Received command for invalid turn"); return; } m_QueuedCommands[turn - (m_CurrentTurn+1)][client].emplace_back(player, m_Simulation2.GetScriptInterface().GetContext(), data); } void CNetTurnManager::FinishedAllCommands(u32 turn, u32 turnLength) { NETTURN_LOG((L"FinishedAllCommands(%d, %d)\n", turn, turnLength)); ENSURE(turn == m_ReadyTurn + 1); m_ReadyTurn = turn; m_TurnLength = turnLength; } bool CNetTurnManager::TurnNeedsFullHash(u32 turn) { // Check immediately for errors caused by e.g. inconsistent game versions // (The hash is computed after the first sim update, so we start at turn == 1) if (turn == 1) return true; // Otherwise check the full state every ~10 seconds in multiplayer games // (TODO: should probably remove this when we're reasonably sure the game // isn't too buggy, since the full hash is still pretty slow) if (turn % 20 == 0) return true; return false; } void CNetTurnManager::EnableTimeWarpRecording(size_t numTurns) { m_TimeWarpStates.clear(); m_TimeWarpNumTurns = numTurns; } void CNetTurnManager::RewindTimeWarp() { if (m_TimeWarpStates.empty()) return; std::stringstream stream(m_TimeWarpStates.back()); m_Simulation2.DeserializeState(stream); m_TimeWarpStates.pop_back(); // Reset the turn manager state, so we won't execute stray commands and // won't do the next snapshot until the appropriate time. // (Ideally we ought to serialise the turn manager state and restore it // here, but this is simpler for now.) ResetState(0, 1); } void CNetTurnManager::QuickSave() { TIMER(L"QuickSave"); std::stringstream stream; if (!m_Simulation2.SerializeState(stream)) { LOGERROR("Failed to quicksave game"); return; } m_QuickSaveState = stream.str(); if (g_GUI) m_QuickSaveMetadata = g_GUI->GetSavedGameData(); else m_QuickSaveMetadata = std::string(); LOGMESSAGERENDER("Quicksaved game"); } void CNetTurnManager::QuickLoad() { TIMER(L"QuickLoad"); if (m_QuickSaveState.empty()) { LOGERROR("Cannot quickload game - no game was quicksaved"); return; } std::stringstream stream(m_QuickSaveState); if (!m_Simulation2.DeserializeState(stream)) { LOGERROR("Failed to quickload game"); return; } if (g_GUI && !m_QuickSaveMetadata.empty()) g_GUI->RestoreSavedGameData(m_QuickSaveMetadata); LOGMESSAGERENDER("Quickloaded game"); // See RewindTimeWarp ResetState(0, 1); } CNetClientTurnManager::CNetClientTurnManager(CSimulation2& simulation, CNetClient& client, int clientId, IReplayLogger& replay) : CNetTurnManager(simulation, DEFAULT_TURN_LENGTH_MP, clientId, replay), m_NetClient(client) { } void CNetClientTurnManager::PostCommand(JS::HandleValue data) { NETTURN_LOG((L"PostCommand()\n")); // Transmit command to server CSimulationMessage msg(m_Simulation2.GetScriptInterface(), m_ClientId, m_PlayerId, m_CurrentTurn + COMMAND_DELAY, data); m_NetClient.SendMessage(&msg); // Add to our local queue //AddCommand(m_ClientId, m_PlayerId, data, m_CurrentTurn + COMMAND_DELAY); // TODO: we should do this when the server stops sending our commands back to us } void CNetClientTurnManager::NotifyFinishedOwnCommands(u32 turn) { NETTURN_LOG((L"NotifyFinishedOwnCommands(%d)\n", turn)); // Send message to the server CEndCommandBatchMessage msg; msg.m_TurnLength = DEFAULT_TURN_LENGTH_MP; // TODO: why do we send this? msg.m_Turn = turn; m_NetClient.SendMessage(&msg); } void CNetClientTurnManager::NotifyFinishedUpdate(u32 turn) { bool quick = !TurnNeedsFullHash(turn); std::string hash; { PROFILE3("state hash check"); ENSURE(m_Simulation2.ComputeStateHash(hash, quick)); } NETTURN_LOG((L"NotifyFinishedUpdate(%d, %hs)\n", turn, Hexify(hash).c_str())); m_Replay.Hash(hash, quick); // Don't send the hash if OOS if (m_HasSyncError) return; // Send message to the server CSyncCheckMessage msg; msg.m_Turn = turn; msg.m_Hash = hash; m_NetClient.SendMessage(&msg); } void CNetClientTurnManager::OnDestroyConnection() { NotifyFinishedOwnCommands(m_CurrentTurn + COMMAND_DELAY); } void CNetClientTurnManager::OnSimulationMessage(CSimulationMessage* msg) { // Command received from the server - store it for later execution AddCommand(msg->m_Client, msg->m_Player, msg->m_Data, msg->m_Turn); } CNetLocalTurnManager::CNetLocalTurnManager(CSimulation2& simulation, IReplayLogger& replay) : CNetTurnManager(simulation, DEFAULT_TURN_LENGTH_SP, 0, replay) { } void CNetLocalTurnManager::PostCommand(JS::HandleValue data) { // Add directly to the next turn, ignoring COMMAND_DELAY, // because we don't need to compensate for network latency AddCommand(m_ClientId, m_PlayerId, data, m_CurrentTurn + 1); } void CNetLocalTurnManager::NotifyFinishedOwnCommands(u32 turn) { FinishedAllCommands(turn, m_TurnLength); } void CNetLocalTurnManager::NotifyFinishedUpdate(u32 UNUSED(turn)) { #if 0 // this hurts performance and is only useful for verifying log replays std::string hash; { PROFILE3("state hash check"); ENSURE(m_Simulation2.ComputeStateHash(hash)); } m_Replay.Hash(hash); #endif } void CNetLocalTurnManager::OnSimulationMessage(CSimulationMessage* UNUSED(msg)) { debug_warn(L"This should never be called"); } CNetReplayTurnManager::CNetReplayTurnManager(CSimulation2& simulation, IReplayLogger& replay) : CNetLocalTurnManager(simulation, replay) { } void CNetReplayTurnManager::StoreReplayCommand(u32 turn, int player, const std::string& command) { // Using the pair we make sure that commands per turn will be processed in the correct order m_ReplayCommands[turn].emplace_back(player, command); } void CNetReplayTurnManager::StoreReplayHash(u32 turn, const std::string& hash, bool quick) { m_ReplayHash[turn] = std::make_pair(hash, quick); } void CNetReplayTurnManager::StoreReplayTurnLength(u32 turn, u32 turnLength) { m_ReplayTurnLengths[turn] = turnLength; // Initialize turn length if (turn == 0) m_TurnLength = m_ReplayTurnLengths[0]; } void CNetReplayTurnManager::StoreFinalReplayTurn(u32 turn) { m_FinalReplayTurn = turn; } void CNetReplayTurnManager::NotifyFinishedUpdate(u32 turn) { if (turn > m_FinalReplayTurn) return; debug_printf("Executing turn %d of %d\n", turn, m_FinalReplayTurn); DoTurn(turn); // Compare hash if it exists in the replay and if we didn't have an OOS already if (m_HasSyncError || m_ReplayHash.find(turn) == m_ReplayHash.end()) return; std::string expectedHash = m_ReplayHash[turn].first; bool quickHash = m_ReplayHash[turn].second; // Compute hash std::string hash; ENSURE(m_Simulation2.ComputeStateHash(hash, quickHash)); hash = Hexify(hash); if (hash != expectedHash) DisplayOOSError(turn, hash, expectedHash, true); } void CNetReplayTurnManager::DoTurn(u32 turn) { // Save turn length m_TurnLength = m_ReplayTurnLengths[turn]; // Simulate commands for that turn for (const std::pair& pair : m_ReplayCommands[turn]) { JS::RootedValue command(m_Simulation2.GetScriptInterface().GetContext()); m_Simulation2.GetScriptInterface().ParseJSON(pair.second, &command); AddCommand(m_ClientId, pair.first, command, m_CurrentTurn + 1); } if (turn == m_FinalReplayTurn) g_GUI->SendEventToAll("ReplayFinished"); } CNetServerTurnManager::CNetServerTurnManager(CNetServerWorker& server) : m_NetServer(server), m_ReadyTurn(1), m_TurnLength(DEFAULT_TURN_LENGTH_MP), m_HasSyncError(false) { // The first turn we will actually execute is number 2, // so store dummy values into the saved lengths list m_SavedTurnLengths.push_back(0); m_SavedTurnLengths.push_back(0); } void CNetServerTurnManager::NotifyFinishedClientCommands(int client, u32 turn) { NETTURN_LOG((L"NotifyFinishedClientCommands(client=%d, turn=%d)\n", client, turn)); // Must be a client we've already heard of ENSURE(m_ClientsReady.find(client) != m_ClientsReady.end()); // Clients must advance one turn at a time ENSURE(turn == m_ClientsReady[client] + 1); m_ClientsReady[client] = turn; // Check whether this was the final client to become ready CheckClientsReady(); } void CNetServerTurnManager::CheckClientsReady() { // See if all clients (including self) are ready for a new turn for (std::map::iterator it = m_ClientsReady.begin(); it != m_ClientsReady.end(); ++it) { NETTURN_LOG((L" %d: %d <=? %d\n", it->first, it->second, m_ReadyTurn)); if (it->second <= m_ReadyTurn) return; // wasn't ready for m_ReadyTurn+1 } // Advance the turn ++m_ReadyTurn; NETTURN_LOG((L"CheckClientsReady: ready for turn %d\n", m_ReadyTurn)); // Tell all clients that the next turn is ready CEndCommandBatchMessage msg; msg.m_TurnLength = m_TurnLength; msg.m_Turn = m_ReadyTurn; m_NetServer.Broadcast(&msg); // Save the turn length in case it's needed later ENSURE(m_SavedTurnLengths.size() == m_ReadyTurn); m_SavedTurnLengths.push_back(m_TurnLength); } void CNetServerTurnManager::NotifyFinishedClientUpdate(int client, const CStrW& playername, u32 turn, const CStr& hash) { // Clients must advance one turn at a time ENSURE(turn == m_ClientsSimulated[client] + 1); m_ClientsSimulated[client] = turn; // Check for OOS only if in sync if (m_HasSyncError) return; m_ClientPlayernames[client] = playername; m_ClientStateHashes[turn][client] = hash; // Find the newest turn which we know all clients have simulated u32 newest = std::numeric_limits::max(); for (std::map::iterator it = m_ClientsSimulated.begin(); it != m_ClientsSimulated.end(); ++it) { if (it->second < newest) newest = it->second; } // For every set of state hashes that all clients have simulated, check for OOS for (std::map >::iterator it = m_ClientStateHashes.begin(); it != m_ClientStateHashes.end(); ++it) { if (it->first > newest) break; // Assume the host is correct (maybe we should choose the most common instead to help debugging) std::string expected = it->second.begin()->second; // Find all players that are OOS on that turn std::vector OOSPlayerNames; for (std::map::iterator cit = it->second.begin(); cit != it->second.end(); ++cit) { NETTURN_LOG((L"sync check %d: %d = %hs\n", it->first, cit->first, Hexify(cit->second).c_str())); if (cit->second != expected) { // Oh no, out of sync m_HasSyncError = true; OOSPlayerNames.push_back(m_ClientPlayernames[cit->first]); } } // Tell everyone about it if (m_HasSyncError) { CSyncErrorMessage msg; msg.m_Turn = it->first; msg.m_HashExpected = expected; for (const CStrW& playername : OOSPlayerNames) { CSyncErrorMessage::S_m_PlayerNames h; h.m_Name = playername; msg.m_PlayerNames.push_back(h); } m_NetServer.Broadcast(&msg); break; } } // Delete the saved hashes for all turns that we've already verified m_ClientStateHashes.erase(m_ClientStateHashes.begin(), m_ClientStateHashes.lower_bound(newest+1)); } void CNetServerTurnManager::InitialiseClient(int client, u32 turn) { NETTURN_LOG((L"InitialiseClient(client=%d, turn=%d)\n", client, turn)); ENSURE(m_ClientsReady.find(client) == m_ClientsReady.end()); m_ClientsReady[client] = turn + 1; m_ClientsSimulated[client] = turn; } void CNetServerTurnManager::UninitialiseClient(int client) { NETTURN_LOG((L"UninitialiseClient(client=%d)\n", client)); ENSURE(m_ClientsReady.find(client) != m_ClientsReady.end()); m_ClientsReady.erase(client); m_ClientsSimulated.erase(client); // Check whether we're ready for the next turn now that we're not // waiting for this client any more CheckClientsReady(); } void CNetServerTurnManager::SetTurnLength(u32 msecs) { m_TurnLength = msecs; } u32 CNetServerTurnManager::GetSavedTurnLength(u32 turn) { ENSURE(turn <= m_ReadyTurn); return m_SavedTurnLengths.at(turn); }