Improve parsing of infolog_full.txt

The new parser identifies regions of the infolog that correspond
to individual games. Each game is further parsed to find:
  GameID
  FirstDesyncIndex
  GameState file names

If the infolog contains GameState file names,
include them in a table in the Issue description.

If the infolog contains multiple games with desyncs, try
to include all of the desync messages in the truncated
infolog.

(cherry picked from commit b98e593)

Author: Mankarse

ChobbyLauncher/CrashReportHelper.cs

@@ -1,9 +1,7 @@
 using System;
 using System.Collections.Generic;
 using System.Diagnostics;
-using System.IO;
 using System.Linq;
-using System.Runtime.InteropServices;
 using System.Text;
 using System.Text.RegularExpressions;
 using System.Threading.Tasks;
@@ -12,7 +10,6 @@
 using Octokit;
 using PlasmaShared;
 using ZkData;
-using FileMode = System.IO.FileMode;
 
 namespace ChobbyLauncher
 {
@@ -25,71 +22,306 @@ public enum CrashType {
 
     public static class CrashReportHelper
     {
+        private const string CrashReportsRepoOwner = "ZeroK-RTS";
+        private const string CrashReportsRepoName = "CrashReports";
+
         private const int MaxInfologSize = 62000;
         private const string InfoLogLineStartPattern = @"(^\[t=\d+:\d+:\d+\.\d+\]\[f=-?\d+\] )";
         private const string InfoLogLineEndPattern = @"(\r?\n|\Z)";
-        public static Issue ReportCrash(string infolog, CrashType type, string engine, string bugReportTitle, string bugReportDescription)
+        private sealed class GameFromLog
+        {
+            public int StartIdxInLog { get; set; }
+            public string GameID { get; set; }
+            public bool HasDesync { get => FirstDesyncIdxInLog.HasValue; }
+            public int? FirstDesyncIdxInLog { get; set; }
+            public List<string> GameStateFileNames { get; set; }
+
+            //Perhaps in future versions, these could be added?
+            //PlayerName
+            //DemoFileName
+            //MapName
+            //ModName
+        }
+
+        private sealed class GameFromLogCollection
+        {
+            public IReadOnlyList<GameFromLog> Games { get; private set; }
+            public GameFromLogCollection(IEnumerable<int> startIndexes)
+            {
+                Games = startIndexes.Select(idx => new GameFromLog { StartIdxInLog = idx }).ToArray();
+            }
+
+            private readonly struct GameStartList : IReadOnlyList<int>
+            {
+                private readonly GameFromLogCollection _this;
+                public GameStartList(GameFromLogCollection v) => _this = v;
+
+                int IReadOnlyList<int>.this[int index] => _this.Games[index].StartIdxInLog;
+
+                int IReadOnlyCollection<int>.Count { get => _this.Games.Count; }
+
+                IEnumerator<int> IEnumerable<int>.GetEnumerator() => _this.Games.Select(g => g.StartIdxInLog).GetEnumerator();
+
+                System.Collections.IEnumerator System.Collections.IEnumerable.GetEnumerator() => ((IEnumerable<int>)this).GetEnumerator();
+            }
+            public IReadOnlyList<int> AsGameStartReadOnlyList() => new GameStartList(this);
+
+            private GameFromLog GetGameForIndex(int idx)
+            {
+                //Equivalent to:
+                //return Games.LastOrDefault(g => g.StartIdxInLog < idx);
+                //but takes advantage of the fact that Games is sorted to have log rather than linear runtime.
+                var lb = AsGameStartReadOnlyList().LowerBoundIndex(idx);
+                return lb == 0 ? null : Games[lb - 1];
+            }
+            public void AddGameStateFileNames(IEnumerable<(int, string)> gameStateFileNames)
+            {
+                foreach (var file in gameStateFileNames)
+                {
+                    var game = GetGameForIndex(file.Item1);
+                    if (game == null)
+                    {
+                        Trace.TraceWarning("[CrashReportHelper] Unable to match GameState file to Game");
+                        continue;
+                    }
+                    if (game.GameStateFileNames == null)
+                    {
+                        game.GameStateFileNames = new List<string>();
+                    }
+
+                    game.GameStateFileNames.Add(file.Item2);
+                }
+            }
+            public void AddDesyncs(IEnumerable<int> desyncs)
+            {
+                foreach (var desync in desyncs)
+                {
+                    var game = GetGameForIndex(desync);
+                    if (game == null)
+                    {
+                        Trace.TraceWarning("[CrashReportHelper] Unable to match Desync to Game");
+                        continue;
+                    }
+                    if (!game.HasDesync)
+                    {
+                        game.FirstDesyncIdxInLog = desync;
+                    }
+                }
+            }
+            public void AddGameIDs(IEnumerable<(int, string)> gameIDs)
+            {
+                foreach (var gameID in gameIDs)
+                {
+                    var game = GetGameForIndex(gameID.Item1);
+                    if (game == null)
+                    {
+                        Trace.TraceWarning("[CrashReportHelper] Unable to match GameID to Game");
+                        continue;
+                    }
+                    if (game.GameID != null)
+                    {
+                        Trace.TraceWarning("[CrashReportHelper] Found multiple GameIDs for Game");
+                        continue;
+                    }
+
+                    game.GameID = gameID.Item2;
+                }
+            }
+        }
+        private static IReadOnlyList<TextTruncator.RegionOfInterest> MakeRegionsOfInterest(int stringLength, IEnumerable<int> pointsOfInterest, IReadOnlyList<int> regionBoundaries)
+        {
+            //Pre:
+            //  pointsOfInterest is sorted
+            //  regionBoundaries is sorted
+
+            //Automatically adds a region at the start and end of the string, that can expand to cover the whole string.
+            //For every element of pointsOfInterest, adds a region with StartLimit/EndLimit corresponding to the relevant regionBoundaries (or the start/end of the string)
+
+            var result = new List<TextTruncator.RegionOfInterest>();
+
+            result.Add(new TextTruncator.RegionOfInterest { PointOfInterest = 0, StartLimit = 0, EndLimit = stringLength });
+            result.AddRange(pointsOfInterest.Select(poi => {
+                var regionEndIndex = Utils.LowerBoundIndex(regionBoundaries, poi);
+                return new TextTruncator.RegionOfInterest
+                {
+                    PointOfInterest = poi,
+                    StartLimit = regionEndIndex == 0 ? 0 : regionBoundaries[regionEndIndex - 1],
+                    EndLimit = regionEndIndex == regionBoundaries.Count ? stringLength : regionBoundaries[regionEndIndex],
+                };
+            }));
+            result.Add(new TextTruncator.RegionOfInterest { PointOfInterest = stringLength, StartLimit = 0, EndLimit = stringLength });
+
+            return result;
+        }
+
+        private static string EscapeMarkdownTableCell(string str) => str.Replace("\r", "").Replace("\n", " ").Replace("|", @"\|");
+        private static string MakeDesyncGameTable(GameFromLogCollection gamesFromLog)
+        {
+            var tableEmpty = true;
+            var sb = new StringBuilder();
+            sb.AppendLine("\n\n|GameID|GameState File|");
+            sb.AppendLine("|-|-|");
+
+            foreach (var game in gamesFromLog.Games.Where(g => g.HasDesync && g.GameStateFileNames != null))
+            {
+                var gameIDString = EscapeMarkdownTableCell(game.GameID ?? "Unknown");
+                foreach (var gameStateFileName in game.GameStateFileNames)
+                {
+                    tableEmpty = false;
+                    sb.AppendLine($"|{gameIDString}|{EscapeMarkdownTableCell(gameStateFileName)}|");
+                }
+            }
+            return tableEmpty ? string.Empty : sb.ToString();
+        }
+
+        private static async Task<Issue> ReportCrash(string infolog, CrashType type, string engine, string bugReportTitle, string bugReportDescription, GameFromLogCollection gamesFromLog)
         {
             try
             {
-                var client = new GitHubClient(new ProductHeaderValue("chobbyla"));
-                client.Credentials = new Credentials(GlobalConst.CrashReportGithubToken);
+                var client = new GitHubClient(new ProductHeaderValue("chobbyla"))
+                {
+                    Credentials = new Credentials(GlobalConst.CrashReportGithubToken)
+                };
+
+                var infologTruncated = TextTruncator.Truncate(infolog, MaxInfologSize, MakeRegionsOfInterest(infolog.Length, gamesFromLog.Games.Where(g => g.HasDesync).Select(g => g.FirstDesyncIdxInLog.Value), gamesFromLog.AsGameStartReadOnlyList()));
 
-                infolog = Truncate(infolog, MaxInfologSize);
+                var desyncDebugInfo = MakeDesyncGameTable(gamesFromLog);
 
-                var createdIssue =
-                    client.Issue.Create("ZeroK-RTS", "CrashReports", new NewIssue($"Spring {type} [{engine}] {bugReportTitle}") { Body = $"{bugReportDescription}\n\n```{infolog}```", })
-                        .Result;
+                var newIssueRequest = new NewIssue($"Spring {type} [{engine}] {bugReportTitle}")
+                {
+                    Body = $"{bugReportDescription}{desyncDebugInfo}"
+                };
+                var createdIssue = await client.Issue.Create(CrashReportsRepoOwner, CrashReportsRepoName, newIssueRequest);
+
+                await client.Issue.Comment.Create(CrashReportsRepoOwner, CrashReportsRepoName, createdIssue.Number, $"infolog_full.txt (truncated):\n\n```{infologTruncated}```");
 
                 return createdIssue;
             }
             catch (Exception ex)
             {
-                Trace.TraceWarning("Problem reporting a bug: {0}", ex);
+                Trace.TraceWarning("[CrashReportHelper] Problem reporting a bug: {0}", ex);
             }
             return null;
         }
-        public static int FindFirstDesyncMessage(string logStr)
+
+        //All infolog parsing is best-effort only.
+        //The infolog file format does not have enough structure to guarantee that it is never misinterpreted.
+
+        private static int[] ReadGameReloads(string logStr)
         {
-            //[t=00:22:43.533864][f=0003461] Sync error for mankarse in frame 3451 (got 927a6f33, correct is 6b550dd1)
+            //Game reload detected by [f=-000001] that follows either the start of the file, or [f={non-negative value}]
+
+            var list = new List<int>();
+
+            var negativeFrameRegex = new Regex(@"f=-(?<=(?<s>^)\[t=\d+:\d+:\d+\.\d+\]\[f=-)\d+\]", RegexOptions.CultureInvariant | RegexOptions.Compiled | RegexOptions.ExplicitCapture | RegexOptions.Multiline, TimeSpan.FromSeconds(30));
+            var nonNegativeFrameRegex = new Regex(@"f=\d(?<=^\[t=\d+:\d+:\d+\.\d+\]\[f=\d)\d*\]", RegexOptions.CultureInvariant | RegexOptions.Compiled | RegexOptions.ExplicitCapture | RegexOptions.Multiline, TimeSpan.FromSeconds(30));
+
+            var idx = 0;
+
             try
             {
-                //See ZkData.Account.IsValidLobbyName
-                var accountNamePattern = @"[_[\]a-zA-Z0-9]{1,25}";
-                var match =
-                    Regex.Match(
-                        logStr,
-                        $@"Sync error for(?<={InfoLogLineStartPattern}Sync error for) {accountNamePattern} in frame \d+ \(got [a-z0-9]+, correct is [a-z0-9]+\){InfoLogLineEndPattern}",
-                        RegexOptions.CultureInvariant | RegexOptions.Compiled | RegexOptions.ExplicitCapture | RegexOptions.Multiline,
-                        TimeSpan.FromSeconds(30));
+                while (true)
+                {
+                    {
+                        var m = negativeFrameRegex.Match(logStr, idx);
+                        if (!m.Success) break;
+                        idx = m.Index;
+                        list.Add(m.Groups["s"].Index);
+                    }
+                    {
+                        var m = nonNegativeFrameRegex.Match(logStr, idx);
+                        if (!m.Success) break;
+                        idx = m.Index;
+                    }
+                }
+                return list.ToArray();
+            }
+            catch (RegexMatchTimeoutException)
+            {
+                Trace.TraceError("\"[CrashReportHelper] RegexMatchTimeoutException in ReadGameReloads");
+                return Array.Empty<int>();
+            }
+        }
+        private static (int, string)[] ReadGameStateFileNames(string logStr)
+        {
+            //See https://github.com/beyond-all-reason/spring/blob/f3ba23635e1462ae2084f10bf9ba777467d16090/rts/System/Sync/DumpState.cpp#L155
 
-                return match.Success ? match.Index : -1;
+            //[t=00:22:43.353840][f=0003461] [DumpState] using dump-file "ClientGameState--749245531-[3461-3461].txt"
+            try
+            {
+                return
+                    Regex
+                        .Matches(
+                            logStr,
+                            $@"(?<={InfoLogLineStartPattern})\[DumpState\] using dump-file ""(?<d>[^{Regex.Escape(System.IO.Path.DirectorySeparatorChar.ToString())}{Regex.Escape(System.IO.Path.AltDirectorySeparatorChar.ToString())}""]+)""{InfoLogLineEndPattern}",
+                            RegexOptions.CultureInvariant | RegexOptions.Compiled | RegexOptions.ExplicitCapture | RegexOptions.Multiline,
+                            TimeSpan.FromSeconds(30))
+                        .Cast<Match>().Select(m => (m.Index, m.Groups["d"].Value)).Distinct()
+                        .ToArray();
             }
-            catch(RegexMatchTimeoutException)
+            catch (RegexMatchTimeoutException)
             {
-                Trace.TraceError("[CrashReportHelper] RegexMatchTimeoutException in FindFirstDesyncMessage");
-                return -1;
+                Trace.TraceError("\"[CrashReportHelper] RegexMatchTimeoutException in ReadClientStateFileNames");
+                return Array.Empty<(int, string)>();
             }
         }
 
-        private static string Truncate(string infolog, int maxSize)
+        private static int[] ReadDesyncs(string logStr)
         {
-            var firstDesync = FindFirstDesyncMessage(infolog);
-            var regionsOfInterest = new List<TextTruncator.RegionOfInterest>(firstDesync == -1 ? 2 : 3);
+            //[t=00:22:43.533864][f=0003461] Sync error for mankarse in frame 3451 (got 927a6f33, correct is 6b550dd1)
 
-            regionsOfInterest.Add(new TextTruncator.RegionOfInterest { PointOfInterest = 0, StartLimit = 0, EndLimit = infolog.Length });
-            if (firstDesync != -1)
+            //See ZkData.Account.IsValidLobbyName
+            var accountNamePattern = @"[_[\]a-zA-Z0-9]{1,25}";
+            try
+            {
+                return
+                    Regex
+                        .Matches(
+                            logStr,
+                            $@"Sync error for(?<={InfoLogLineStartPattern}Sync error for) {accountNamePattern} in frame \d+ \(got [a-z0-9]+, correct is [a-z0-9]+\){InfoLogLineEndPattern}",
+                            RegexOptions.CultureInvariant | RegexOptions.Compiled | RegexOptions.ExplicitCapture | RegexOptions.Multiline,
+                            TimeSpan.FromSeconds(30))
+                        .Cast<Match>().Select(m => m.Index).ToArray();
+            }
+            catch (RegexMatchTimeoutException)
             {
-                regionsOfInterest.Add(new TextTruncator.RegionOfInterest { PointOfInterest = firstDesync, StartLimit = 0, EndLimit = infolog.Length });
+                Trace.TraceError("\"[CrashReportHelper] RegexMatchTimeoutException in ReadDesyncs");
+                return Array.Empty<int>();
             }
-            regionsOfInterest.Add(new TextTruncator.RegionOfInterest { PointOfInterest = infolog.Length, StartLimit = 0, EndLimit = infolog.Length });
+        }
+
+
+        private static (int, string)[] ReadGameIDs(string logStr)
+        {
+            //[t=00:19:00.246149][f=-000001] GameID: 6065f665e92c7942def2c0c17c703e72
 
-            return TextTruncator.Truncate(infolog, maxSize, regionsOfInterest);
+            try
+            {
+                return
+                    Regex
+                        .Matches(
+                            logStr,
+                            $@"GameID:(?<={InfoLogLineStartPattern}GameID:) (?<g>[0-9a-zA-Z]+){InfoLogLineEndPattern}",
+                            RegexOptions.CultureInvariant | RegexOptions.Compiled | RegexOptions.ExplicitCapture | RegexOptions.Multiline,
+                            TimeSpan.FromSeconds(30))
+                        .Cast<Match>().Select(m => { var g = m.Groups["g"]; return (g.Index, g.Value); }).ToArray();
+            }
+            catch (RegexMatchTimeoutException)
+            {
+                Trace.TraceError("\"[CrashReportHelper] RegexMatchTimeoutException in ReadGameIDs");
+                return Array.Empty<(int, string)>();
+            }
         }
 
         public static void CheckAndReportErrors(string logStr, bool springRunOk, string bugReportTitle, string bugReportDescription, string engineVersion)
         {
-            var syncError = FindFirstDesyncMessage(logStr) != -1;
+            var gamesFromLog = new GameFromLogCollection(ReadGameReloads(logStr));
+
+            gamesFromLog.AddGameStateFileNames(ReadGameStateFileNames(logStr));
+            gamesFromLog.AddDesyncs(ReadDesyncs(logStr));
+            gamesFromLog.AddGameIDs(ReadGameIDs(logStr));
+
+            var syncError = gamesFromLog.Games.Any(g => g.HasDesync);
             if (syncError) Trace.TraceWarning("Sync error detected");
 
             var openGlFail = logStr.Contains("No OpenGL drivers installed.") ||
@@ -139,11 +371,16 @@ public static void CheckAndReportErrors(string logStr, bool springRunOk, string
                                   : luaErr       ? CrashType.LuaError
                                                  : CrashType.Crash;
 
-                    var ret = ReportCrash(logStr,
-                        crashType,
-                        engineVersion,
-                        bugReportTitle,
-                        bugReportDescription);
+                    var ret =
+                        ReportCrash(
+                            logStr,
+                            crashType,
+                            engineVersion,
+                            bugReportTitle,
+                            bugReportDescription,
+                            gamesFromLog)
+                        .GetAwaiter().GetResult();
+
                     if (ret != null)
                         try
                         {