Log comparing test

Tests/CodexTests/ScalabilityTests/OneClientLargeFileTests.cs

@@ -50,15 +50,39 @@ namespace CodexTests.ScalabilityTests
                 .WithStorageQuota(20.GB())
             );
 
+            var startUtc = DateTime.UtcNow;
+            var endUtc = DateTime.UtcNow;
+
+            var fastMap = new Dictionary<string, int>();
+            var slowMap = new Dictionary<string, int>();
+
             var times = new List<TimeSpan>();
             for (var i = 0; i < 100; i++)
             {
                 Thread.Sleep(1000);
                 var file = GenerateTestFile(100.MB());
-                times.Add(Stopwatch.Measure(GetTestLog(), "Upload_" + i, () =>
+                startUtc = DateTime.UtcNow;
+                var duration = Stopwatch.Measure(GetTestLog(), "Upload_" + i, () =>
                 {
                     node.UploadFile(file);
-                }));
+                });
+                times.Add(duration);
+                endUtc = DateTime.UtcNow;
+
+                // We collect the log of the node during the upload.
+                // We count the line occurances.
+                // If the upload was fast, add it to the fast-map.
+                // If it was slow, add it to the slow-map.
+                // After the test, we can compare and hopefully see what the node was doing during the slow uploads
+                // that it wasn't doing during the fast ones.
+                if (duration.TotalSeconds < 12)
+                {
+                    AddToLogMap(fastMap, node, startUtc, endUtc);
+                }
+                else if (duration.TotalSeconds > 25)
+                {
+                    AddToLogMap(slowMap, node, startUtc, endUtc);
+                }
             }
 
             Log("Upload times:");
@@ -66,6 +90,37 @@ namespace CodexTests.ScalabilityTests
             {
                 Log(Time.FormatDuration(t));
             }
+            Log("Fast map:");
+            foreach (var entry in fastMap.OrderByDescending(p => p.Value))
+            {
+                if (entry.Value > 9)
+                {
+                    Log($"'{entry.Key}' = {entry.Value}");
+                }
+            }
+            Log("Slow map:");
+            foreach (var entry in slowMap.OrderByDescending(p => p.Value))
+            {
+                if (entry.Value > 9)
+                {
+                    Log($"'{entry.Key}' = {entry.Value}");
+                }
+            }
+        }
+
+        private void AddToLogMap(Dictionary<string, int>  map, ICodexNode node, DateTime startUtc, DateTime endUtc)
+        {
+            var log = Ci.DownloadLog(node, 1000000);
+            log.IterateLines(line =>
+            {
+                var log = CodexLogLine.Parse(line);
+                if (log == null) return;
+                if (log.TimestampUtc < startUtc) return;
+                if (log.TimestampUtc > endUtc) return;
+
+                if (map.ContainsKey(log.Message)) map[log.Message] += 1;
+                else map.Add(log.Message, 1);
+            });
         }
     }
 }