public string CheckForDesync(ClientSyncOpinion other)
{
if (!mapStates.Select(m => m.mapId).SequenceEqual(other.mapStates.Select(m => m.mapId)))
{
return("Map instances don't match");
}
for (var i = 0; i < mapStates.Count; i++)
{
if (!mapStates[i].randomStates.SequenceEqual(other.mapStates[i].randomStates))
{
return($"Wrong random state on map {mapStates[i].mapId}");
}
}
if (!worldRandomStates.SequenceEqual(other.worldRandomStates))
{
return("Wrong random state for the world");
}
if (!commandRandomStates.SequenceEqual(other.commandRandomStates))
{
return("Random state from commands doesn't match");
}
if (!simulating && !other.simulating && desyncStackTraceHashes.Any() && other.desyncStackTraceHashes.Any() && !desyncStackTraceHashes.SequenceEqual(other.desyncStackTraceHashes))
{
return("Trace hashes don't match");
}
return(null);
}
/// <summary>
/// Saves the local stack traces (saved by calls to <see cref="TryAddStackTraceForDesyncLog"/>) around the area
/// where a desync occurred to disk, and sends a packet to the arbiter (via the host) to make it do the same
/// </summary>
/// <param name="local">The local client's opinion, to dump the stacks from</param>
/// <param name="remote">A remote client's opinion, used to find where the desync occurred</param>
private void SaveStackTracesToDisk(ClientSyncOpinion local, ClientSyncOpinion remote)
{
Log.Message($"Saving {local.desyncStackTraces.Count} traces to disk");
//Find the length of whichever stack trace is shorter.
int diffAt = -1;
int count = Math.Min(local.desyncStackTraceHashes.Count, remote.desyncStackTraceHashes.Count);
//Find the point at which the hashes differ - this is where the desync occurred.
for (int i = 0; i < count; i++)
{
if (local.desyncStackTraceHashes[i] != remote.desyncStackTraceHashes[i])
{
diffAt = i;
break;
}
}
if (diffAt == -1)
{
diffAt = count;
}
//Dump the stack traces to disk
File.WriteAllText("local_traces.txt", local.GetFormattedStackTracesForRange(diffAt - 40, diffAt + 40));
//Trigger a call to ClientConnection#HandleDebug on the arbiter instance so that arbiter_traces.txt is saved too
Multiplayer.Client.Send(Packets.Client_Debug, local.startTick, diffAt - 40, diffAt + 40);
}
/// <summary>
/// Saves the local stack traces (saved by calls to <see cref="TryAddStackTraceForDesyncLog"/>) around the area
/// where a desync occurred to disk, and sends a packet to the arbiter (via the host) to make it do the same
/// </summary>
/// <param name="local">The local client's opinion, to dump the stacks from</param>
/// <param name="remote">A remote client's opinion, used to find where the desync occurred</param>
private void SaveStackTracesToDisk(ClientSyncOpinion local, ClientSyncOpinion remote)
{
Log.Message($"Saving {local.desyncStackTraces.Count} traces to disk");
//Dump the stack traces to disk
File.WriteAllText("local_traces.txt", GetDesyncStackTraces(local, remote, out var diffAt));
//Trigger a call to ClientConnection#HandleDebug on the arbiter instance so that arbiter_traces.txt is saved too
Multiplayer.Client.Send(Packets.Client_Debug, local.startTick, diffAt - 40, diffAt + 40);
}
/// <summary>
/// Deserializes the sync file (Representing a Client Opinion) with the given filename inside the given zip file
/// and dumps its data in a human-readable format to the provided string builder
/// </summary>
/// <param name="builder">The builder to append the data to</param>
/// <param name="zip">The zip file that contains the file with the provided name</param>
/// <param name="filename">The name of the sync file to dump</param>
/// <returns>The deserialized client opinion that was dumped</returns>
private static ClientSyncOpinion DeserializeAndPrintSyncInfo(StringBuilder builder, ZipFile zip, string filename)
{
builder.AppendLine($"[{filename}]");
var sync = ClientSyncOpinion.Deserialize(new ByteReader(zip[filename].GetBytes()));
builder.AppendLine($"Start: {sync.startTick}");
builder.AppendLine($"Was simulating: {sync.simulating}");
builder.AppendLine($"Map count: {sync.mapStates.Count}");
builder.AppendLine($"Last map state: {sync.mapStates.Select(m => $"{m.mapId}/{m.randomStates.LastOrDefault()}/{m.randomStates.Count}").ToStringSafeEnumerable()}");
builder.AppendLine($"Last world state: {sync.worldRandomStates.LastOrDefault()}/{sync.worldRandomStates.Count}");
builder.AppendLine($"Last cmd state: {sync.commandRandomStates.LastOrDefault()}/{sync.commandRandomStates.Count}");
builder.AppendLine($"Trace hashes: {sync.desyncStackTraceHashes.Count}");
return(sync);
}
/// <summary>
/// Get a nicely formatted string containing local stack traces (saved by calls to <see cref="TryAddStackTraceForDesyncLog"/>)
/// around the area where a desync occurred
/// </summary>
/// <param name="dumpFrom">The client's opinion to dump the stacks from</param>
/// <param name="compareTo">Another client's opinion, used to find where the desync occurred</param>
/// <returns></returns>
private string GetDesyncStackTraces(ClientSyncOpinion dumpFrom, ClientSyncOpinion compareTo, out int diffAt)
{
//Find the length of whichever stack trace is shorter.
diffAt = -1;
int count = Math.Min(dumpFrom.desyncStackTraceHashes.Count, compareTo.desyncStackTraceHashes.Count);
//Find the point at which the hashes differ - this is where the desync occurred.
for (int i = 0; i < count; i++)
{
if (dumpFrom.desyncStackTraceHashes[i] != compareTo.desyncStackTraceHashes[i])
{
diffAt = i;
break;
}
}
if (diffAt == -1)
{
diffAt = count;
}
return(dumpFrom.GetFormattedStackTracesForRange(diffAt - 40, diffAt + 40, diffAt));
}
public void HandleDesyncCheck(ByteReader data)
{
Multiplayer.game?.sync.AddClientOpinionAndCheckDesync(ClientSyncOpinion.Deserialize(data));
}
/// <summary>
/// Adds a client opinion to the <see cref="knownClientOpinions"/> list and checks that it matches the most recent currently in there. If not, a desync event is fired.
/// </summary>
/// <param name="newOpinion">The <see cref="ClientSyncOpinion"/> to add and check.</param>
public void AddClientOpinionAndCheckDesync(ClientSyncOpinion newOpinion)
{
//If we've already desynced, don't even bother
if (Multiplayer.session.desynced)
{
return;
}
//If we're skipping ticks, again, don't bother
if (TickPatch.Skipping)
{
return;
}
//If this is the first client opinion we have nothing to compare it with, so just add it
if (knownClientOpinions.Count == 0)
{
knownClientOpinions.Add(newOpinion);
return;
}
if (knownClientOpinions[0].isLocalClientsOpinion == newOpinion.isLocalClientsOpinion)
{
knownClientOpinions.Add(newOpinion);
if (knownClientOpinions.Count > 30)
{
knownClientOpinions.RemoveAt(0);
}
}
else
{
//Remove all opinions that started before this one, as it's the most up to date one
while (knownClientOpinions.Count > 0 && knownClientOpinions[0].startTick < newOpinion.startTick)
{
knownClientOpinions.RemoveAt(0);
}
//If there are none left, we don't need to compare this new one
if (knownClientOpinions.Count == 0)
{
knownClientOpinions.Add(newOpinion);
}
else if (knownClientOpinions.First().startTick == newOpinion.startTick)
{
//If these two contain the same tick range - i.e. they start at the same time, cause they should continue to the current tick, then do a comparison.
var oldOpinion = knownClientOpinions.RemoveFirst();
//Actually do the comparison to find any desync
var desyncMessage = oldOpinion.CheckForDesync(newOpinion);
if (desyncMessage != null)
{
MpLog.Log($"Desynced after tick {lastValidTick}: {desyncMessage}");
Multiplayer.session.desynced = true;
OnMainThread.Enqueue(() => HandleDesync(oldOpinion, newOpinion, desyncMessage));
}
else
{
//Update fields
lastValidTick = oldOpinion.startTick;
arbiterWasPlayingOnLastValidTick = Multiplayer.session.ArbiterPlaying;
}
}
}
}
/// <summary>
/// Called by <see cref="AddClientOpinionAndCheckDesync"/> if the newly added opinion doesn't match with what other ones.
/// </summary>
/// <param name="oldOpinion">The first up-to-date client opinion present in <see cref="knownClientOpinions"/>, that disagreed with the new one</param>
/// <param name="newOpinion">The opinion passed to <see cref="AddClientOpinionAndCheckDesync"/> that disagreed with the currently known opinions.</param>
/// <param name="desyncMessage">The error message that explains exactly what desynced.</param>
private void HandleDesync(ClientSyncOpinion oldOpinion, ClientSyncOpinion newOpinion, string desyncMessage)
{
Multiplayer.Client.Send(Packets.Client_Desynced);
//Identify which of the two sync infos is local, and which is the remote.
var local = oldOpinion.isLocalClientsOpinion ? oldOpinion : newOpinion;
var remote = !oldOpinion.isLocalClientsOpinion ? oldOpinion : newOpinion;
//Print arbiter desync stacktrace if it exists
if (local.desyncStackTraces.Any())
{
SaveStackTracesToDisk(local, remote);
}
try
{
//Get the filename of the next desync file to create.
var desyncFilePath = FindFileNameForNextDesyncFile();
//Initialize the Replay object.
var replay = Replay.ForSaving(Replay.ReplayFile(desyncFilePath, Multiplayer.DesyncsDir));
//Write the universal replay data (i.e. world and map folders, and the info file) so this desync can be reviewed as a standard replay.
replay.WriteCurrentData();
//Dump our current game object.
var savedGame = ScribeUtil.WriteExposable(Current.Game, "game", true, ScribeMetaHeaderUtility.WriteMetaHeader);
using (var zip = replay.ZipFile)
using (var desyncReport = new ZipFile()) //Create a desync report for uploading to the reports server.
{
//Write the local sync data
var syncLocal = local.Serialize();
zip.AddEntry("sync_local", syncLocal);
desyncReport.AddEntry("sync_local", syncLocal);
//Write the remote sync data
var syncRemote = remote.Serialize();
zip.AddEntry("sync_remote", syncRemote);
desyncReport.AddEntry("sync_remote", syncRemote);
//Dump the entire save file to the zip.
zip.AddEntry("game_snapshot", savedGame);
// desyncReport.AddEntry("game_snapshot", savedGame); //This ends up being about 15MB, we really don't want that.
//Add local stack traces
zip.AddEntry("local_stacks", GetDesyncStackTraces(local, remote, out _));
desyncReport.AddEntry("local_stacks", GetDesyncStackTraces(local, remote, out _));
//Add remote's stack traces
zip.AddEntry("remote_stacks", GetDesyncStackTraces(remote, local, out _));
desyncReport.AddEntry("remote_stacks", GetDesyncStackTraces(remote, local, out _));
//Prepare the desync info
var desyncInfo = new StringBuilder();
desyncInfo.AppendLine("###Tick Data###")
.AppendLine($"Arbiter Connected And Playing|||{Multiplayer.session.ArbiterPlaying}")
.AppendLine($"Last Valid Tick - Local|||{lastValidTick}")
.AppendLine($"Arbiter Present on Last Tick|||{arbiterWasPlayingOnLastValidTick}")
.AppendLine("\n###Version Data###")
.AppendLine($"Multiplayer Mod Version|||{MpVersion.Version}")
.AppendLine($"Rimworld Version and Rev|||{VersionControl.CurrentVersionStringWithRev}")
.AppendLine("\n###Debug Options###")
.AppendLine($"Multiplayer Debug Build - Client|||{MpVersion.IsDebug}")
.AppendLine($"Multiplayer Debug Build - Host|||{Multiplayer.WorldComp.debugMode}")
.AppendLine($"Rimworld Developer Mode - Client|||{Prefs.DevMode}")
.AppendLine("\n###Server Info###")
.AppendLine($"Player Count|||{Multiplayer.session.players.Count}")
.AppendLine("\n###CPU Info###")
.AppendLine($"Processor Name|||{SystemInfo.processorType}")
.AppendLine($"Processor Speed (MHz)|||{SystemInfo.processorFrequency}")
.AppendLine($"Thread Count|||{SystemInfo.processorCount}")
.AppendLine("\n###GPU Info###")
.AppendLine($"GPU Family|||{SystemInfo.graphicsDeviceVendor}")
.AppendLine($"GPU Type|||{SystemInfo.graphicsDeviceType}")
.AppendLine($"GPU Name|||{SystemInfo.graphicsDeviceName}")
.AppendLine($"GPU VRAM|||{SystemInfo.graphicsMemorySize}")
.AppendLine("\n###RAM Info###")
.AppendLine($"Physical Memory Present|||{SystemInfo.systemMemorySize}")
.AppendLine("\n###OS Info###")
.AppendLine($"OS Type|||{SystemInfo.operatingSystemFamily}")
.AppendLine($"OS Name and Version|||{SystemInfo.operatingSystem}");
//Save debug info to the zip
zip.AddEntry("desync_info", desyncInfo.ToString());
desyncReport.AddEntry("desync_info", desyncInfo.ToString());
zip.Save();
//Add the basic info to the report
desyncReport.AddEntry("info", zip["info"].GetBytes());
desyncReport.AddEntry("ign", Multiplayer.session.GetPlayerInfo(Multiplayer.session.playerId).username);
desyncReport.AddEntry("steamName", SteamUtility.SteamPersonaName);
//Report desync to the server
var request = (HttpWebRequest)WebRequest.Create("https://multiplayer.samboycoding.me/api/desync/upload");
// var request = (HttpWebRequest) WebRequest.Create("http://localhost:4193/api/desync/upload");
request.Method = "POST";
request.ContentType = "application/zip";
using (var stream = new MemoryStream())
{
desyncReport.Save(stream);
stream.Seek(0, SeekOrigin.Begin);
request.ContentLength = stream.Length;
var data = new byte[stream.Length];
stream.Read(data, 0, data.Length);
using (var outStream = request.GetRequestStream())
outStream.Write(data, 0, data.Length);
}
//TODO: Some user interaction here?
try
{
using (var response = (HttpWebResponse)request.GetResponse())
{
if (response.StatusCode != HttpStatusCode.OK)
{
Log.Error("Failed to report desync; Status code " + response.StatusCode);
}
else
{
using (var stream = response.GetResponseStream())
using (var reader = new StreamReader(stream))
{
var desyncReportId = reader.ReadToEnd();
Log.Message("Desync Reported with ID " + desyncReportId);
}
}
}
}
catch (WebException e)
{
Log.Error("Failed to report desync; " + e.Message);
}
}
}
catch (Exception e)
{
Log.Error($"Exception writing desync info: {e}");
}
Find.WindowStack.windows.Clear();
Find.WindowStack.Add(new DesyncedWindow(desyncMessage));
}
/// <summary>
/// Attempts to generate user-readable desync info from the given replay
/// </summary>
/// <param name="replay">The replay to generate the info from</param>
/// <returns>The desync info as a human-readable string</returns>
public static string GenerateFromReplay(Replay replay)
{
var text = new StringBuilder();
//Open the replay zip
using (var zip = replay.ZipFile)
{
try
{
text.AppendLine("[header]");
using (var reader = new XmlTextReader(new MemoryStream(zip["game_snapshot"].GetBytes())))
{
//Read to the <root> element
reader.ReadToNextElement();
//Read to the <meta> element
reader.ReadToNextElement();
//Append the entire <meta> element, including game version, mod IDs, and mod names, to the text
text.AppendLine(reader.ReadOuterXml());
}
}
catch (Exception e)
{
text.AppendLine(e.Message);
}
text.AppendLine();
try
{
//The info is the replay save data, including game name, protocol version, and assembly hashes
text.AppendLine("[info]");
text.AppendLine(zip["info"].GetString());
}
catch
{
}
text.AppendLine();
ClientSyncOpinion local = null;
try
{
//Local Client Opinion data
local = DeserializeAndPrintSyncInfo(text, zip, "sync_local");
}
catch
{
}
text.AppendLine();
ClientSyncOpinion remote = null;
try
{
//Remote Client Opinion data
remote = DeserializeAndPrintSyncInfo(text, zip, "sync_remote");
}
catch
{
}
text.AppendLine();
try
{
//Desync info
text.AppendLine("[desync_info]");
//Backwards compatibility! (AKA v1 support)
if (zip["desync_info"].GetString().StartsWith("###"))
{
//This is a V2 file, dump as-is
text.AppendLine(zip["desync_info"].GetString());
}
else
{
//V1 file, parse it.
var desyncInfo = new ByteReader(zip["desync_info"].GetBytes());
text.AppendLine($"Arbiter online: {desyncInfo.ReadBool()}");
text.AppendLine($"Last valid tick: {desyncInfo.ReadInt32()}");
text.AppendLine($"Last valid arbiter online: {desyncInfo.ReadBool()}");
text.AppendLine($"Mod version: {desyncInfo.ReadString()}");
text.AppendLine($"Mod is debug: {desyncInfo.ReadBool()}");
text.AppendLine($"Dev mode: {desyncInfo.ReadBool()}");
text.AppendLine($"Player count: {desyncInfo.ReadInt32()}");
text.AppendLine($"Game debug mode: {desyncInfo.ReadBool()}");
}
}
catch
{
}
text.AppendLine();
//Append random state comparison saved from the desync
if (local != null && remote != null)
{
text.AppendLine("[compare]");
for (int i = 0; i < Math.Min(local.mapStates.Count, remote.mapStates.Count); i++)
{
var localMap = local.mapStates[i].randomStates;
var remoteMap = remote.mapStates[i].randomStates;
bool equal = localMap.SequenceEqual(remoteMap);
text.AppendLine($"Map {local.mapStates[i].mapId}: {equal}");
if (!equal)
{
for (int j = 0; j < Math.Min(localMap.Count, remoteMap.Count); j++)
{
text.AppendLine($"{localMap[j]} {remoteMap[j]} {(localMap[j] != remoteMap[j] ? "x" : "")}");
}
}
}
text.AppendLine($"World: {local.worldRandomStates.SequenceEqual(remote.worldRandomStates)}");
text.AppendLine($"Cmds: {local.commandRandomStates.SequenceEqual(remote.commandRandomStates)}");
}
text.AppendLine();
try
{
//Add commands random states saved with the replay
text.AppendLine("[map_cmds]");
foreach (var cmd in Replay.DeserializeCmds(zip["maps/000_0_cmds"].GetBytes()))
{
PrintCmdInfo(text, cmd);
}
}
catch
{
}
text.AppendLine();
try
{
//Add world random states saved with the replay
text.AppendLine("[world_cmds]");
foreach (var cmd in Replay.DeserializeCmds(zip["world/000_cmds"].GetBytes()))
{
PrintCmdInfo(text, cmd);
}
}
catch
{
}
}
return(text.ToString());
}
/// <summary>
/// Called by <see cref="AddClientOpinionAndCheckDesync"/> if the newly added opinion doesn't match with what other ones.
/// </summary>
/// <param name="oldOpinion">The first up-to-date client opinion present in <see cref="knownClientOpinions"/>, that disagreed with the new one</param>
/// <param name="newOpinion">The opinion passed to <see cref="AddClientOpinionAndCheckDesync"/> that disagreed with the currently known opinions.</param>
/// <param name="desyncMessage">The error message that explains exactly what desynced.</param>
private void HandleDesync(ClientSyncOpinion oldOpinion, ClientSyncOpinion newOpinion, string desyncMessage)
{
Multiplayer.Client.Send(Packets.Client_Desynced);
//Identify which of the two sync infos is local, and which is the remote.
var local = oldOpinion.isLocalClientsOpinion ? oldOpinion : newOpinion;
var remote = !oldOpinion.isLocalClientsOpinion ? oldOpinion : newOpinion;
//Print arbiter desync stacktrace if it exists
if (local.desyncStackTraces.Any())
{
SaveStackTracesToDisk(local, remote);
}
try
{
//Get the filename of the next desync file to create.
var desyncFilePath = FindFileNameForNextDesyncFile();
//Initialize the Replay object.
var replay = Replay.ForSaving(Replay.ReplayFile(desyncFilePath, Multiplayer.DesyncsDir));
//Write the universal replay data (i.e. world and map folders, and the info file) so this desync can be reviewed as a standard replay.
replay.WriteCurrentData();
//Dump our current game object.
var savedGame = ScribeUtil.WriteExposable(Current.Game, "game", true, ScribeMetaHeaderUtility.WriteMetaHeader);
using (var zip = replay.ZipFile)
{
//Write the local sync data
var syncLocal = local.Serialize();
zip.AddEntry("sync_local", syncLocal);
//Write the remote sync data
var syncRemote = remote.Serialize();
zip.AddEntry("sync_remote", syncRemote);
//Dump the entire save file to the zip.
zip.AddEntry("game_snapshot", savedGame);
//Prepare the desync info
var desyncInfo = new StringBuilder();
desyncInfo.AppendLine("###Tick Data###")
.AppendLine($"Arbiter Connected And Playing|||{Multiplayer.session.ArbiterPlaying}")
.AppendLine($"Last Valid Tick - Local|||{lastValidTick}")
.AppendLine($"Last Valid Tick - Arbiter|||{arbiterWasPlayingOnLastValidTick}")
.AppendLine("\n###Version Data###")
.AppendLine($"Multiplayer Mod Version|||{MpVersion.Version}")
.AppendLine($"Rimworld Version and Rev|||{VersionControl.CurrentVersionStringWithRev}")
.AppendLine("\n###Debug Options###")
.AppendLine($"Multiplayer Debug Build - Client|||{MpVersion.IsDebug}")
.AppendLine($"Multiplayer Debug Build - Host|||{Multiplayer.WorldComp.debugMode}")
.AppendLine($"Rimworld Developer Mode - Client|||{Prefs.DevMode}")
.AppendLine("\n###Server Info###")
.AppendLine($"Player Count|||{Multiplayer.session.players.Count}")
.AppendLine("\n###CPU Info###")
.AppendLine($"Processor Name|||{SystemInfo.processorType}")
.AppendLine($"Processor Speed (MHz)|||{SystemInfo.processorFrequency}")
.AppendLine($"Thread Count|||{SystemInfo.processorCount}")
.AppendLine("\n###GPU Info###")
.AppendLine($"GPU Family|||{SystemInfo.graphicsDeviceVendor}")
.AppendLine($"GPU Type|||{SystemInfo.graphicsDeviceType}")
.AppendLine($"GPU Name|||{SystemInfo.graphicsDeviceName}")
.AppendLine($"GPU VRAM|||{SystemInfo.graphicsMemorySize}")
.AppendLine("\n###RAM Info###")
.AppendLine($"Physical Memory Present|||{SystemInfo.systemMemorySize}")
.AppendLine("\n###OS Info###")
.AppendLine($"OS Type|||{SystemInfo.operatingSystemFamily}")
.AppendLine($"OS Name and Version|||{SystemInfo.operatingSystem}");
//Save debug info to the zip
zip.AddEntry("desync_info", desyncInfo.ToString());
zip.Save();
}
}
catch (Exception e)
{
Log.Error($"Exception writing desync info: {e}");
}
Find.WindowStack.windows.Clear();
Find.WindowStack.Add(new DesyncedWindow(desyncMessage));
}
