diff --git a/DistTestCore/DistTest.cs b/DistTestCore/DistTest.cs index 76c966a..9f4dc1e 100644 --- a/DistTestCore/DistTest.cs +++ b/DistTestCore/DistTest.cs @@ -187,6 +187,7 @@ namespace DistTestCore private void CreateNewTestLifecycle() { var testName = GetCurrentTestName(); + fixtureLog.WriteLogTag(); Stopwatch.Measure(fixtureLog, $"Setup for {testName}", () => { lock (lifecycleLock) diff --git a/DistTestCore/Helpers/PeerConnectionTestHelpers.cs b/DistTestCore/Helpers/PeerConnectionTestHelpers.cs index 93c8f21..7b326ff 100644 --- a/DistTestCore/Helpers/PeerConnectionTestHelpers.cs +++ b/DistTestCore/Helpers/PeerConnectionTestHelpers.cs @@ -6,6 +6,7 @@ namespace DistTestCore.Helpers { public class PeerConnectionTestHelpers { + private static string Nl = Environment.NewLine; private readonly Random random = new Random(); private readonly DistTest test; @@ -40,9 +41,11 @@ namespace DistTestCore.Helpers if (pairs.Any()) { - test.Log($"Unsuccessful! Peers are not fully-connected: {string.Join(",", nodes.Select(n => n.GetName()))}"); - Assert.Fail(string.Join(Environment.NewLine, pairs.Select(p => p.GetMessage()))); - test.Log(string.Join(Environment.NewLine, pairs.Select(p => p.GetMessage()))); + var pairDetails = string.Join(Nl, pairs.SelectMany(p => p.GetResultMessages())); + + test.Log($"Connections failed:{Nl}{pairDetails}"); + + Assert.Fail(string.Join(Nl, pairs.SelectMany(p => p.GetResultMessages()))); } else { @@ -52,18 +55,19 @@ namespace DistTestCore.Helpers private static void RetryWhilePairs(List pairs, Action action) { - var timeout = DateTime.UtcNow + TimeSpan.FromSeconds(30); - while (pairs.Any() && timeout > DateTime.UtcNow) + var timeout = DateTime.UtcNow + TimeSpan.FromMinutes(5); + while (pairs.Any(p => p.Inconclusive) && timeout > DateTime.UtcNow) { action(); - if (pairs.Any()) Time.Sleep(TimeSpan.FromSeconds(2)); + Time.Sleep(TimeSpan.FromSeconds(2)); } } private void CheckAndRemoveSuccessful(List pairs) { - var checkTasks = pairs.Select(p => Task.Run(() => + // For large sets, don't try and do all of them at once. + var checkTasks = pairs.Take(20).Select(p => Task.Run(() => { ApplyRandomDelay(); p.Check(); @@ -71,14 +75,16 @@ namespace DistTestCore.Helpers Task.WaitAll(checkTasks); + var pairDetails = new List(); foreach (var pair in pairs.ToArray()) { if (pair.Success) { - test.Log(pair.GetMessage()); + pairDetails.AddRange(pair.GetResultMessages()); pairs.Remove(pair); } } + test.Log($"Connections successful:{Nl}{string.Join(Nl, pairDetails)}"); } private static Entry[] CreateEntries(IOnlineCodexNode[] nodes) @@ -89,7 +95,7 @@ namespace DistTestCore.Helpers if (incorrectDiscoveryEndpoints.Any()) { Assert.Fail("Some nodes contain peer records with incorrect discovery ip/port information: " + - string.Join(Environment.NewLine, incorrectDiscoveryEndpoints)); + string.Join(Nl, incorrectDiscoveryEndpoints)); } return entries; @@ -181,6 +187,7 @@ namespace DistTestCore.Helpers public PeerConnectionState AKnowsB { get; private set; } public PeerConnectionState BKnowsA { get; private set; } public bool Success { get { return AKnowsB == PeerConnectionState.Connection && BKnowsA == PeerConnectionState.Connection; } } + public bool Inconclusive { get { return AKnowsB == PeerConnectionState.Unknown || BKnowsA == PeerConnectionState.Unknown; } } public void Check() { @@ -188,35 +195,21 @@ namespace DistTestCore.Helpers bToATime = Measure(() => BKnowsA = Knows(B, A)); } - public string GetMessage() - { - return GetResultMessage() + GetTimePostfix(); - } - public override string ToString() { - return $"[{GetMessage()}]"; + return $"[{string.Join(",", GetResultMessages())}]"; } - private string GetResultMessage() + public string[] GetResultMessages() { var aName = A.ToString(); var bName = B.ToString(); - if (Success) + return new[] { - return $"{aName} and {bName} know each other."; - } - - return $"[{aName}-->{bName}] = {AKnowsB} AND [{aName}<--{bName}] = {BKnowsA}"; - } - - private string GetTimePostfix() - { - var aName = A.ToString(); - var bName = B.ToString(); - - return $" ({aName}->{bName}: {aToBTime.TotalMinutes} seconds, {bName}->{aName}: {bToATime.TotalSeconds} seconds)"; + $"[{aName} --> {bName}] = {AKnowsB} ({aToBTime.TotalSeconds} seconds)", + $"[{aName} <-- {bName}] = {BKnowsA} ({bToATime.TotalSeconds} seconds)" + }; } private static TimeSpan Measure(Action action) @@ -230,6 +223,7 @@ namespace DistTestCore.Helpers { lock (a) { + Thread.Sleep(10); var peerId = b.Response.id; try diff --git a/DistTestCore/TestLifecycle.cs b/DistTestCore/TestLifecycle.cs index 5249960..50b665a 100644 --- a/DistTestCore/TestLifecycle.cs +++ b/DistTestCore/TestLifecycle.cs @@ -25,6 +25,8 @@ namespace DistTestCore PrometheusStarter = new PrometheusStarter(this, workflowCreator); GethStarter = new GethStarter(this, workflowCreator); testStart = DateTime.UtcNow; + + Log.WriteLogTag(); } public BaseLog Log { get; } diff --git a/Logging/BaseLog.cs b/Logging/BaseLog.cs index 6ff6da5..1164d1b 100644 --- a/Logging/BaseLog.cs +++ b/Logging/BaseLog.cs @@ -21,11 +21,7 @@ namespace Logging { get { - if (logFile == null) - { - logFile = new LogFile(GetFullName(), "log"); - WriteLogTag(); - } + if (logFile == null) logFile = new LogFile(GetFullName(), "log"); return logFile; } } @@ -77,7 +73,7 @@ namespace Logging return new LogFile($"{GetFullName()}_{GetSubfileNumber()}", ext); } - private void WriteLogTag() + public void WriteLogTag() { var runId = NameUtils.GetRunId(); var category = NameUtils.GetCategoryName(); diff --git a/Logging/StatusLog.cs b/Logging/StatusLog.cs index a62c70a..0913023 100644 --- a/Logging/StatusLog.cs +++ b/Logging/StatusLog.cs @@ -20,7 +20,7 @@ namespace Logging { Write(new StatusLogJson { - time = DateTime.UtcNow.ToString("o"), + @timestamp = DateTime.UtcNow.ToString("o"), runid = NameUtils.GetRunId(), status = resultStatus, testid = NameUtils.GetTestId(), @@ -49,7 +49,7 @@ namespace Logging public class StatusLogJson { - public string time { get; set; } = string.Empty; + public string @timestamp { get; set; } = string.Empty; public string runid { get; set; } = string.Empty; public string status { get; set; } = string.Empty; public string testid { get; set; } = string.Empty;