Much nicer logging by means of container name-override and long-id log replacements

DistTestCore/Codex/CodexContainerRecipe.cs

@@ -5,8 +5,8 @@ namespace DistTestCore.Codex
 {
     public class CodexContainerRecipe : ContainerRecipeFactory
     {
-        public const string DockerImage = "thatbenbierens/nim-codex:sha-92ea752";
+        //public const string DockerImage = "thatbenbierens/nim-codex:sha-9716635";
-        //public const string DockerImage = "thatbenbierens/codexlocal:latest";
+        public const string DockerImage = "thatbenbierens/codexlocal:latest";
         public const string MetricsPortTag = "metrics_port";
 
         protected override string Image => DockerImage;

DistTestCore/Codex/CodexStartupConfig.cs

@@ -5,6 +5,7 @@ namespace DistTestCore.Codex
 {
     public class CodexStartupConfig
     {
+        public string? NameOverride { get; set; }
         public Location Location { get; set; }
         public CodexLogLevel? LogLevel { get; set; }
         public ByteSize? StorageQuota { get; set; }

DistTestCore/CodexNodeGroup.cs

@@ -75,6 +75,10 @@ namespace DistTestCore
             {
                 var debugInfo = access.GetDebugInfo();
                 if (debugInfo == null || string.IsNullOrEmpty(debugInfo.id)) throw new InvalidOperationException("Unable to get debug-info from codex node at startup.");
+
+                var nodePeerId = debugInfo.id;
+                var nodeName = access.Container.Name;
+                lifecycle.Log.AddStringReplace(nodePeerId, $"___{nodeName}___");
             }
             catch (Exception e)
             {

DistTestCore/CodexSetup.cs

@@ -6,6 +6,7 @@ namespace DistTestCore
 {
     public interface ICodexSetup
     {
+        ICodexSetup WithName(string name);
         ICodexSetup At(Location location);
         ICodexSetup WithLogLevel(CodexLogLevel level);
         ICodexSetup WithBootstrapNode(IOnlineCodexNode node);
@@ -24,6 +25,12 @@ namespace DistTestCore
             NumberOfNodes = numberOfNodes;
         }
 
+        public ICodexSetup WithName(string name)
+        {
+            NameOverride = name;
+            return this;
+        }
+
         public ICodexSetup At(Location location)
         {
             Location = location;

DistTestCore/CodexStarter.cs

@@ -1,4 +1,5 @@
 using DistTestCore.Codex;
+using DistTestCore.Marketplace;
 using KubernetesWorkflow;
 
 namespace DistTestCore
@@ -18,10 +19,7 @@ namespace DistTestCore
             LogStart($"Starting {codexSetup.Describe()}...");
             var gethStartResult = lifecycle.GethStarter.BringOnlineMarketplaceFor(codexSetup);
 
-            var startupConfig = new StartupConfig();
+            var startupConfig = CreateStartupConfig(gethStartResult, codexSetup);
-            startupConfig.Add(codexSetup);
-            startupConfig.Add(gethStartResult);
-
             var containers = StartCodexContainers(startupConfig, codexSetup.NumberOfNodes, codexSetup.Location);
 
             var metricAccessFactory = lifecycle.PrometheusStarter.CollectMetricsFor(codexSetup, containers);
@@ -56,7 +54,16 @@ namespace DistTestCore
             var workflow = CreateWorkflow();
             workflow.DownloadContainerLog(container, logHandler);
         }
-        
+
+        private StartupConfig CreateStartupConfig(GethStartResult gethStartResult, CodexSetup codexSetup)
+        {
+            var startupConfig = new StartupConfig();
+            startupConfig.NameOverride = codexSetup.NameOverride;
+            startupConfig.Add(codexSetup);
+            startupConfig.Add(gethStartResult);
+            return startupConfig;
+        }
+
         private RunningContainers StartCodexContainers(StartupConfig startupConfig, int numberOfNodes, Location location)
         {
             var workflow = CreateWorkflow();

DistTestCore/DistTest.cs

@@ -103,6 +103,20 @@ namespace DistTestCore
             return lifecycle.FileManager.GenerateTestFile(size);
         }
 
+        public IOnlineCodexNode SetupCodexBootstrapNode()
+        {
+            return SetupCodexBootstrapNode(s => { });
+        }
+
+        public IOnlineCodexNode SetupCodexBootstrapNode(Action<ICodexSetup> setup)
+        {
+            return SetupCodexNode(s =>
+            {
+                setup(s);
+                s.WithName("Bootstrap");
+            });
+        }
+
         public IOnlineCodexNode SetupCodexNode()
         {
             return SetupCodexNode(s => { });

DistTestCore/Marketplace/MarketplaceAccess.cs

@@ -114,7 +114,7 @@ namespace DistTestCore.Marketplace
 
         private void Log(string msg)
         {
-            log.Log($"{codexAccess.Container.GetName()} {msg}");
+            log.Log($"{codexAccess.Container.Name} {msg}");
         }
     }
 

DistTestCore/Metrics/MetricsAccess.cs

@@ -29,7 +29,7 @@ namespace DistTestCore.Metrics
             var metricSet = GetMetricWithTimeout(metricName);
             var metricValue = metricSet.Values[0].Value;
 
-            log.Log($"{node.GetName()} metric '{metricName}' = {metricValue}");
+            log.Log($"{node.Name} metric '{metricName}' = {metricValue}");
 
             Assert.That(metricValue, constraint, message);
         }

DistTestCore/OnlineCodexNode.cs

@@ -41,7 +41,7 @@ namespace DistTestCore
 
         public string GetName()
         {
-            return CodexAccess.Container.GetName();
+            return CodexAccess.Container.Name;
         }
 
         public CodexDebugResponse GetDebugInfo()

KubernetesWorkflow/RunningContainers.cs

@@ -15,26 +15,35 @@
 
         public string Describe()
         {
-            return string.Join(",", Containers.Select(c => c.GetName()));
+            return string.Join(",", Containers.Select(c => c.Name));
         }
     }
 
     public class RunningContainer
     {
-        public RunningContainer(RunningPod pod, ContainerRecipe recipe, Port[] servicePorts)
+        public RunningContainer(RunningPod pod, ContainerRecipe recipe, Port[] servicePorts, StartupConfig startupConfig)
         {
             Pod = pod;
             Recipe = recipe;
             ServicePorts = servicePorts;
+            Name = GetContainerName(recipe, startupConfig);
         }
 
-        public string GetName()
+        public string Name { get; }
-        {
-            return $"<{Recipe.Name}>";
-        }
-
         public RunningPod Pod { get; }
         public ContainerRecipe Recipe { get; }
         public Port[] ServicePorts { get; }
+
+        private string GetContainerName(ContainerRecipe recipe, StartupConfig startupConfig)
+        {
+            if (!string.IsNullOrEmpty(startupConfig.NameOverride))
+            {
+                return $"<{startupConfig.NameOverride}{recipe.Number}>";
+            }
+            else
+            {
+                return $"<{recipe.Name}>";
+            }
+        }
     }
 }

KubernetesWorkflow/StartupConfig.cs

@@ -4,6 +4,8 @@
     {
         private readonly List<object> configs = new List<object>();
 
+        public string? NameOverride { get; set; }
+
         public void Add(object config)
         {
             configs.Add(config);

KubernetesWorkflow/StartupWorkflow.cs

@@ -26,7 +26,7 @@ namespace KubernetesWorkflow
 
                 var runningPod = controller.BringOnline(recipes, location);
 
-                return new RunningContainers(startupConfig, runningPod, CreateContainers(runningPod, recipes));
+                return new RunningContainers(startupConfig, runningPod, CreateContainers(runningPod, recipes, startupConfig));
             });
         }
 
@@ -62,10 +62,10 @@ namespace KubernetesWorkflow
             });
         }
 
-        private RunningContainer[] CreateContainers(RunningPod runningPod, ContainerRecipe[] recipes)
+        private RunningContainer[] CreateContainers(RunningPod runningPod, ContainerRecipe[] recipes, StartupConfig startupConfig)
         {
             log.Debug();
-            return recipes.Select(r => new RunningContainer(runningPod, r, runningPod.GetServicePortsForContainerRecipe(r))).ToArray();
+            return recipes.Select(r => new RunningContainer(runningPod, r, runningPod.GetServicePortsForContainerRecipe(r), startupConfig)).ToArray();
         }
 
         private ContainerRecipe[] CreateRecipes(int numberOfContainers, ContainerRecipeFactory recipeFactory, StartupConfig startupConfig)

Logging/BaseLog.cs

@@ -1,13 +1,13 @@
-using System.Diagnostics;
+using Utils;
-using Utils;
 
 namespace Logging
 {
     public abstract class BaseLog
     {
+        private readonly bool debug;
+        private readonly List<BaseLogStringReplacement> replacements = new List<BaseLogStringReplacement>();
         private bool hasFailed;
         private LogFile? logFile;
-        private readonly bool debug;
 
         protected BaseLog(bool debug)
         {
@@ -27,7 +27,7 @@ namespace Logging
 
         public void Log(string message)
         {
-            LogFile.Write(message);
+            LogFile.Write(ApplyReplacements(message));
         }
 
         public void Debug(string message = "", int skipFrames = 0)
@@ -35,7 +35,8 @@ namespace Logging
             if (debug)
             {
                 var callerName = DebugStack.GetCallerName(skipFrames);
-                Log($"(debug)({callerName}) {message}");
+                // We don't use Log because in the debug output we should not have any replacements.
+                LogFile.Write($"(debug)({callerName}) {message}");
             }
         }
 
@@ -50,5 +51,38 @@ namespace Logging
             hasFailed = true;
             LogFile.ConcatToFilename("_FAILED");
         }
+
+        public void AddStringReplace(string from, string to)
+        {
+            replacements.Add(new BaseLogStringReplacement(from, to));
+        }
+
+        private string ApplyReplacements(string str)
+        {
+            foreach (var replacement in replacements)
+            {
+                str = replacement.Apply(str);
+            }
+            return str;
+        }
+    }
+
+    public class BaseLogStringReplacement
+    {
+        private readonly string from;
+        private readonly string to;
+
+        public BaseLogStringReplacement(string from, string to)
+        {
+            this.from = from;
+            this.to = to;
+
+            if (string.IsNullOrEmpty(from) || string.IsNullOrEmpty(to) || from == to) throw new ArgumentException();
+        }
+
+        public string Apply(string msg)
+        {
+            return msg.Replace(from, to);
+        }
     }
 }

Tests/BasicTests/PeerTests.cs

@@ -10,7 +10,7 @@ namespace Tests.BasicTests
         [Test]
         public void TwoNodes()
         {
-            var primary = SetupCodexNode();
+            var primary = SetupCodexBootstrapNode();
             var secondary = SetupCodexNode(s => s.WithBootstrapNode(primary));
 
             primary.ConnectToPeer(secondary); // This is required for the switchPeers to show up.
@@ -29,7 +29,7 @@ namespace Tests.BasicTests
         [TestCase(10)]
         public void VariableNodes(int number)
         {
-            var bootstrap = SetupCodexNode();
+            var bootstrap = SetupCodexBootstrapNode();
             var nodes = SetupCodexNodes(number, s => s.WithBootstrapNode(bootstrap));
 
             var file = GenerateTestFile(10.MB());
@@ -69,8 +69,8 @@ namespace Tests.BasicTests
             //Log.Debug($"Looking for {b.id} in engine-peers [{enginePeers}]");
             Log.Debug($"{a.id} is looking for {b.id} in switch-peers [{switchPeers}]");
 
-            //Assert.That(a.enginePeers.Any(p => p.peerId == b.id), $"Expected peerId '{b.id}' not found in engine-peers [{enginePeers}]");
+            //Assert.That(a.enginePeers.Any(p => p.peerId == b.id), $"{a.id} was looking for '{b.id}' in engine-peers [{enginePeers}] but it was not found.");
-            Assert.That(a.switchPeers.Any(p => p.peerId == b.id), $"Expected peerId '{b.id}' not found in switch-peers [{switchPeers}]");
+            Assert.That(a.switchPeers.Any(p => p.peerId == b.id), $"{a.id} was looking for '{b.id}' in switch-peers [{switchPeers}] but it was not found.");
         }
     }
 }