Sets up tests for symmetric, asymmetric and binary speed checks

ProjectPlugins/CodexPlugin/CodexAccess.cs

@@ -234,8 +234,15 @@ namespace CodexPlugin
                 .CreateEndpoint(GetAddress(), "/api/codex/v1/", Container.Name);
         }
 
+        public static Address? UploaderOverride { get; set; } = null;
+        public static Address? DownloaderOverride { get; set; } = null;
+
         private Address GetAddress()
         {
+            if (GetName().ToLowerInvariant().Contains("upload") && UploaderOverride != null) return UploaderOverride;
+            if (GetName().ToLowerInvariant().Contains("download") && DownloaderOverride != null) return DownloaderOverride;
+
+
             return Container.Containers.Single().GetAddress(CodexContainerRecipe.ApiPortTag);
         }
 

ProjectPlugins/CodexPlugin/CodexLogLine.cs

@@ -48,6 +48,11 @@ namespace CodexPlugin
         public string Message { get; set; } = string.Empty;
         public Dictionary<string, string> Attributes { get; private set; } = new Dictionary<string, string>();
 
+        public override string ToString()
+        {
+            return Message;
+        }
+
         /// <summary>
         /// After too much time spent cursing at regexes, here's what I got:
         /// Parses input string into 'key=value' pair, considerate of quoted (") values.

ProjectPlugins/CodexPlugin/CodexNode.cs

@@ -22,6 +22,8 @@ namespace CodexPlugin
         ContentId UploadFile(TrackedFile file, string contentType, string contentDisposition, Action<Failure> onFailure);
         TrackedFile? DownloadContent(ContentId contentId, string fileLabel = "");
         TrackedFile? DownloadContent(ContentId contentId, Action<Failure> onFailure, string fileLabel = "");
+        (TrackedFile?, TimeSpan) DownloadContentT(ContentId contentId, string fileLabel = "");
+        (TrackedFile?, TimeSpan) DownloadContentT(ContentId contentId, Action<Failure> onFailure, string fileLabel = "");
         LocalDataset DownloadStreamless(ContentId cid);
         /// <summary>
         /// TODO: This will monitor the quota-used of the node until 'size' bytes are added. That's a very bad way
@@ -189,10 +191,20 @@ namespace CodexPlugin
 
         public TrackedFile? DownloadContent(ContentId contentId, string fileLabel = "")
         {
-            return DownloadContent(contentId, DoNothing, fileLabel);
+            return DownloadContentT(contentId, fileLabel).Item1;
         }
 
         public TrackedFile? DownloadContent(ContentId contentId, Action<Failure> onFailure, string fileLabel = "")
+        {
+            return DownloadContentT(contentId, onFailure, fileLabel).Item1;
+        }
+
+        public (TrackedFile?, TimeSpan) DownloadContentT(ContentId contentId, string fileLabel = "")
+        {
+            return DownloadContentT(contentId, DoNothing, fileLabel);
+        }
+
+        public (TrackedFile?, TimeSpan) DownloadContentT(ContentId contentId, Action<Failure> onFailure, string fileLabel = "")
         {
             var file = tools.GetFileManager().CreateEmptyFile(fileLabel);
             hooks.OnFileDownloading(contentId);
@@ -205,7 +217,7 @@ namespace CodexPlugin
             transferSpeeds.AddDownloadSample(size, measurement);
             hooks.OnFileDownloaded(size, contentId);
 
-            return file;
+            return (file, measurement);
         }
 
         public LocalDataset DownloadStreamless(ContentId cid)

SpeedCheckTests/Parallelism.cs

@@ -0,0 +1,6 @@
+using NUnit.Framework;
+
+[assembly: LevelOfParallelism(1)]
+namespace CodexTests
+{
+}

SpeedCheckTests/SpeedCheckTests.csproj

@@ -0,0 +1,19 @@
+<Project Sdk="Microsoft.NET.Sdk">
+
+  <PropertyGroup>
+    <TargetFramework>net8.0</TargetFramework>
+    <ImplicitUsings>enable</ImplicitUsings>
+    <Nullable>enable</Nullable>
+  </PropertyGroup>
+	<ItemGroup>
+		<PackageReference Include="nunit" Version="3.13.3" />
+		<PackageReference Include="NUnit3TestAdapter" Version="4.4.2" />
+		<PackageReference Include="Microsoft.NET.Test.Sdk" Version="17.5.0" />
+	</ItemGroup>
+
+	<ItemGroup>
+		<ProjectReference Include="..\ProjectPlugins\CodexPlugin\CodexPlugin.csproj" />
+		<ProjectReference Include="..\Tests\DistTestCore\DistTestCore.csproj" />
+		<ProjectReference Include="..\Tests\ExperimentalTests\ExperimentalTests.csproj" />
+	</ItemGroup>
+</Project>

SpeedCheckTests/SpeedTest.cs

@@ -0,0 +1,107 @@
+using CodexPlugin;
+using CodexTests;
+using NUnit.Framework;
+using System.Diagnostics;
+using System.Drawing;
+using Utils;
+
+namespace SpeedCheckTests
+{
+    [TestFixture]
+    public class SpeedTest : CodexDistTest
+    {
+        [Test]
+        public void Symmetric()
+        {
+            // Symmetric: A node always sends a reply to every message it receives.
+            CodexContainerRecipe.DockerImageOverride = "thatbenbierens/nim-codex:blkex-cancelpresence-27-f";
+
+            var uploader = StartCodex(s => s.WithName("SymUploader"));
+            var downloader = StartCodex(s => s.WithName("SymDownloader").WithBootstrapNode(uploader));
+            var timeTaken = PerformTest(uploader, downloader);
+
+            Console.WriteLine($"Symmetric time: {Time.FormatDuration(timeTaken)}");
+
+            Assert.That(timeTaken, Is.LessThan(TimeSpan.FromSeconds(10.0)), 
+                $"Symmetric: Too slow. Expected less than 10 seconds but was: {Time.FormatDuration(timeTaken)}");
+        }
+
+        [Test]
+        public void Asymmetric()
+        {
+            // Asymmetric: A node does not always send a reply when a message is received.
+            CodexContainerRecipe.DockerImageOverride = "thatbenbierens/nim-codex:blkex-cancelpresence-27-s";
+
+            var uploader = StartCodex(s => s.WithName("AsymUploader"));
+            var downloader = StartCodex(s => s.WithName("AsymDownloader").WithBootstrapNode(uploader));
+            var timeTaken = PerformTest(uploader, downloader);
+
+            Console.WriteLine($"Asymmetric time: {Time.FormatDuration(timeTaken)}");
+
+            Assert.That(timeTaken, Is.LessThan(TimeSpan.FromSeconds(10.0)),
+                $"Asymmetric: Too slow. Expected less than 10 seconds but was: {Time.FormatDuration(timeTaken)}");
+        }
+
+        [Test]
+        public void Binary()
+        {
+            // Docker image not used: Here for api check.
+            CodexContainerRecipe.DockerImageOverride = "thatbenbierens/nim-codex:blkex-cancelpresence-27-f";
+
+            var binary = "C:\\Projects\\nim-codex\\build\\codex.exe";
+            if (!File.Exists(binary)) throw new Exception("TODO: Update binary path");
+
+            var uploadInfo = new ProcessStartInfo
+            {
+                FileName = binary,
+                Arguments = "--data-dir=upload_data " +
+                "--api-port=8081 " +
+                "--nat=127.0.0.1 " +
+                "--disc-ip=127.0.0.1 " +
+                "--disc-port=8091 " +
+                "--listen-addrs=/ip4/127.0.0.1/tcp/8071",
+                UseShellExecute = true,
+            };
+
+            var uploadProcess = Process.Start(uploadInfo);
+
+            Thread.Sleep(5000);
+            if (uploadProcess == null || uploadProcess.HasExited) throw new Exception("Node exited.");
+
+            CodexAccess.UploaderOverride = new Address("http://localhost", 8081);
+            var uploader = StartCodex(s => s.WithName("BinaryUploader"));
+            var spr = uploader.GetSpr();
+            
+            var downloadProcess = Process.Start(binary,
+                "--data-dir=download_data " +
+                "--api-port=8082 " +
+                "--nat=127.0.0.1 " +
+                "--disc-ip=127.0.0.1 " +
+                "--disc-port=8092 " +
+                "--listen-addrs=/ip4/127.0.0.1/tcp/8072 " +
+                "--bootstrap-node=" + spr
+            );
+
+            CodexAccess.DownloaderOverride = new Address("http://localhost", 8082);
+            var downloader = StartCodex(s => s.WithName("BinaryDownloader"));
+
+            var timeTaken = PerformTest(uploader, downloader);
+
+            uploadProcess.Kill();
+            downloadProcess.Kill();
+
+            Console.WriteLine($"Binary time: {Time.FormatDuration(timeTaken)}");
+
+            Assert.That(timeTaken, Is.LessThan(TimeSpan.FromSeconds(10.0)),
+                $"Binary: Too slow. Expected less than 10 seconds but was: {Time.FormatDuration(timeTaken)}");
+        }
+
+        private TimeSpan PerformTest(ICodexNode uploader, ICodexNode downloader)
+        {
+            var testFile = GenerateTestFile(100.MB());
+            var contentId = uploader.UploadFile(testFile);
+            var (downloadedFile, timeTaken) = downloader.DownloadContentT(contentId);
+            return timeTaken;
+        }
+    }
+}

Tests/CodexReleaseTests/DataTests/TwoClientTest.cs

@@ -14,8 +14,67 @@ namespace CodexReleaseTests.DataTests
     public class TwoClientTests : CodexDistTest
     {
         [Test]
-        public void TwoClientTest()
+        [Combinatorial]
+        public void TwoClientTest(
+            [Values(
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-2", // S don't send cancel-presence messages
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-1", // F ignore cancel-presence messages
+            //"codexstorage/nim-codex:sha-4b5c355-dist-tests", // F unmodified
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-3", // F same as 1 but logging
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-4", // S no cancel-presence-msg, no fromCancel field
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-5", // F all-presence = cancel? return from handler
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-6", // F no cancel-presence-msg, but if any cancel send empty presence msg
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-7", // F same but logs outgoing empty presence message. (msg is empty structure)
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-8", // crashes F? eventtimelogging
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-9", // crashes S? eventtimelogging + no cancel-presence-msg (should be slow)
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-10", // F eventtimelogging (should be fast)
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-11", // S eventtimelogging + no cancel-presence-msg (should be slow)
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-12", // F upload and download event logging (should be fast)
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-13", // S same but with no cancel-presence-msg (should be slow)
+
+            //"thatbenbierens/nim-codex:peerselecta-1", // F PR update (yes cancel-presence-msg)
+            //"thatbenbierens/nim-codex:peerselecta-2", // S PR update (no cancel-presence-msg)
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-14", // F new logging
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-15", // S new logging
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-16-f", // F more logging
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-16-s", // S more logging
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-17-f", // F "tick" every 100 milliseconds
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-17-s", // S same but slow
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-18-f", // F "tick" every 10 milliseconds
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-18-s", // S same but slow
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-19-f", // F sending/sent/received logs
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-19-s", // S same but slow
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-20-f", // F sending/sent/received logs + number
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-20-s", // S same but slow
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-21-f", // F libp2p lpchannel.write logs
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-21-s", // S same but slow
+
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-22-f", // F chronos stream write logs
+            //"thatbenbierens/nim-codex:blkex-cancelpresence-22-s", // S same but slow
+
+            "thatbenbierens/nim-codex:blkex-cancelpresence-23-f", // F chronos stream write logs in libp2p hand-off
+            "thatbenbierens/nim-codex:blkex-cancelpresence-23-s", // S same but slow
+
+            "thatbenbierens/nim-codex:blkex-cancelpresence-25-f", // F chronos stream write logs in libp2p hand-off with ticks
+            "thatbenbierens/nim-codex:blkex-cancelpresence-25-s",  // S same but slow
+
+            "thatbenbierens/nim-codex:blkex-cancelpresence-27-f", // F chronos stream write logs in libp2p hand-off with ticks adds names
+            "thatbenbierens/nim-codex:blkex-cancelpresence-27-s"  // S same but slow
+            )] string img
+        )
         {
+            CodexContainerRecipe.DockerImageOverride = img;
+
             var uploader = StartCodex(s => s.WithName("Uploader"));
             var downloader = StartCodex(s => s.WithName("Downloader").WithBootstrapNode(uploader));
 
@@ -23,25 +82,111 @@ namespace CodexReleaseTests.DataTests
         }
 
         [Test]
-        [Ignore("Location selection is currently unavailable.")]
-        public void TwoClientsTwoLocationsTest()
+        public void ParseLogs()
         {
-            var locations = Ci.GetKnownLocations();
-            if (locations.NumberOfLocations < 2)
+            var path = "d:\\Dev\\cs-codex-dist-tests\\Tests\\CodexReleaseTests\\bin\\Debug\\net8.0\\CodexTestLogs\\2025-01\\09\\13-58-28Z_TwoClientTests\\";
+            var file1 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-27-f]_000001_Downloader1.log");
+            var file2 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-27-f]_000000_Uploader0.log");
+            var file3 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-27-s]_000001_Downloader1.log");
+            var file4 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-27-s]_000000_Uploader0.log");
+
+            var lines = File.ReadAllLines(file3);
+            var clines = new List<CodexLogLine>();
+            foreach (var line in lines)
             {
-                Assert.Inconclusive("Two-locations test requires 2 nodes to be available in the cluster.");
-                return;
+                var cline = CodexLogLine.Parse(line);
+                if (cline != null) clines.Add(cline);
             }
 
-            var uploader = Ci.StartCodexNode(s => s.WithName("Uploader").At(locations.Get(0)));
-            var downloader = Ci.StartCodexNode(s => s.WithName("Downloader").WithBootstrapNode(uploader).At(locations.Get(1)));
+            var gaps = new List<Gap>();
+            for (var i = 0; i < clines.Count; i++)
+            {
+                var line = clines[i];
+
+
+                // todo:
+//TRC 2025-01-09 13:59:14.501+00:00 chronosread                                topics="libp2p chronosstream custom" tid=1 ticks=424485 name=ChronosStream count=32669
+//TRC 2025-01-09 13:59:14.501+00:00 chronosread                                topics="libp2p chronosstream custom" tid=1 ticks=600 name=ChronosStream count=32670
+//TRC 2025-01-09 13:59:14.501+00:00 readOnce                                   topics="libp2p mplexchannel custom" tid=1 s=16U*uBBR7j:677fd62fe0c5bd152c675e42:677fd62ff7548faf70a27174 bytes=1 count=32671
+//TRC 2025-01-09 13:59:14.501+00:00 readOnce                                   topics="libp2p mplexchannel custom" tid=1 s=16U*uBBR7j:677fd62fe0c5bd152c675e42:677fd62ff7548faf70a27174 bytes=73 count=32672
+//TRC 2025-01-09 13:59:14.501+00:00 MsgReceived                                topics="codex blockexcnetworkpeer" tid=1 num=7 count=32673
+
+                // read to received!???
+
+                // run in cluster, same effect???
+                // run native, same effect?
+
+                if (line.Message == "MsgSending")
+                {
+                    // the next line is lpc-write-fast, then chronoswrite
+                    if (i + 2  < clines.Count)
+                    {
+                        var next = clines[i + 2];
+                        if (next.Message == "chronoswrite")
+                        {
+                            // got ya!
+                            gaps.Add(new Gap(line, next));
+                        }
+                        else
+                        {
+                            var aaaa = "what is it?!";
+                        }
+                    }
+                }
+            }
+
+            gaps = gaps.OrderByDescending(g => g.GapSpan.TotalMilliseconds).ToList();
+
+            var iiii = 0;
+
+        }
+
+        public class Gap
+        {
+            public Gap(CodexLogLine line, CodexLogLine next)
+            {
+                Line = line;
+                Next = next;
+            }
+
+            public CodexLogLine Line { get; }
+            public CodexLogLine Next { get; }
+
+            public TimeSpan GapSpan
+            {
+                get
+                {
+                    return Next.TimestampUtc - Line.TimestampUtc;
+                }
+            }
+
+            public override string ToString()
+            {
+                return $"[{GapSpan.TotalMilliseconds} ms]";
+            }
+        }
+
+        private void ProcessTimes(CodexLogLine cline)
+        {
+            // reqCreatedTime
+            // wantHaveSentTimes
+            // presenceRecvTimes
+            // wantBlkSentTimes
+            // blkRecvTimes
+            // cancelSentTimes
+            // resolveTimes
+
+        }
+
+        public class BlockReqTimes
+        {
+            public TimeSpan CreateToWantHaveSent { get; set; }
 
-            PerformTwoClientTest(uploader, downloader);
         }
 
         private void PerformTwoClientTest(ICodexNode uploader, ICodexNode downloader)
         {
-            PerformTwoClientTest(uploader, downloader, 10.MB());
+            PerformTwoClientTest(uploader, downloader, 100.MB());
         }
 
         private void PerformTwoClientTest(ICodexNode uploader, ICodexNode downloader, ByteSize size)
@@ -51,11 +196,12 @@ namespace CodexReleaseTests.DataTests
             var contentId = uploader.UploadFile(testFile);
             AssertNodesContainFile(contentId, uploader);
 
-            var downloadedFile = downloader.DownloadContent(contentId);
+            var (downloadedFile, timeTaken) = downloader.DownloadContentT(contentId);
             AssertNodesContainFile(contentId, uploader, downloader);
 
+            Assert.That(timeTaken, Is.LessThan(TimeSpan.FromSeconds(15.0)), "Too slow!");
+
             testFile.AssertIsEqual(downloadedFile);
-            CheckLogForErrors(uploader, downloader);
         }
     }
 }

Tests/DistTestCore/Configuration.cs

@@ -14,7 +14,7 @@ namespace DistTestCore
             kubeConfigFile = GetNullableEnvVarOrDefault("KUBECONFIG", null);
             logPath = GetEnvVarOrDefault("LOGPATH", "CodexTestLogs");
             dataFilesPath = GetEnvVarOrDefault("DATAFILEPATH", "TestDataFiles");
-            AlwaysDownloadContainerLogs = !string.IsNullOrEmpty(GetEnvVarOrDefault("ALWAYS_LOGS", ""));
+            AlwaysDownloadContainerLogs = true; // !string.IsNullOrEmpty(GetEnvVarOrDefault("ALWAYS_LOGS", ""));
         }
 
         public Configuration(string? kubeConfigFile, string logPath, string dataFilesPath)

cs-codex-dist-testing.sln

@@ -82,6 +82,8 @@ Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "ExperimentalTests", "Tests\
 EndProject
 Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "BlockchainUtils", "Framework\BlockchainUtils\BlockchainUtils.csproj", "{4648B5AA-A0A7-44BA-89BC-2FD57370943C}"
 EndProject
+Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "SpeedCheckTests", "SpeedCheckTests\SpeedCheckTests.csproj", "{5D134D9A-DC61-4472-8F47-92250C8DB5CC}"
+EndProject
 Global
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
 		Debug|Any CPU = Debug|Any CPU
@@ -220,6 +222,10 @@ Global
 		{4648B5AA-A0A7-44BA-89BC-2FD57370943C}.Debug|Any CPU.Build.0 = Debug|Any CPU
 		{4648B5AA-A0A7-44BA-89BC-2FD57370943C}.Release|Any CPU.ActiveCfg = Release|Any CPU
 		{4648B5AA-A0A7-44BA-89BC-2FD57370943C}.Release|Any CPU.Build.0 = Release|Any CPU
+		{5D134D9A-DC61-4472-8F47-92250C8DB5CC}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
+		{5D134D9A-DC61-4472-8F47-92250C8DB5CC}.Debug|Any CPU.Build.0 = Debug|Any CPU
+		{5D134D9A-DC61-4472-8F47-92250C8DB5CC}.Release|Any CPU.ActiveCfg = Release|Any CPU
+		{5D134D9A-DC61-4472-8F47-92250C8DB5CC}.Release|Any CPU.Build.0 = Release|Any CPU
 	EndGlobalSection
 	GlobalSection(SolutionProperties) = preSolution
 		HideSolutionNode = FALSE
@@ -258,6 +264,7 @@ Global
 		{639A0603-4E80-465B-BB59-AB02F1DEEF5A} = {88C2A621-8A98-4D07-8625-7900FC8EF89E}
 		{BA7369CD-7C2F-4075-8E35-98BCC19EE203} = {88C2A621-8A98-4D07-8625-7900FC8EF89E}
 		{4648B5AA-A0A7-44BA-89BC-2FD57370943C} = {81AE04BC-CBFA-4E6F-B039-8208E9AFAAE7}
+		{5D134D9A-DC61-4472-8F47-92250C8DB5CC} = {88C2A621-8A98-4D07-8625-7900FC8EF89E}
 	EndGlobalSection
 	GlobalSection(ExtensibilityGlobals) = postSolution
 		SolutionGuid = {237BF0AA-9EC4-4659-AD9A-65DEB974250C}