diff --git a/ProjectPlugins/CodexPlugin/CodexLogLine.cs b/ProjectPlugins/CodexPlugin/CodexLogLine.cs index d2758145..d47717af 100644 --- a/ProjectPlugins/CodexPlugin/CodexLogLine.cs +++ b/ProjectPlugins/CodexPlugin/CodexLogLine.cs @@ -48,6 +48,11 @@ namespace CodexPlugin public string Message { get; set; } = string.Empty; public Dictionary Attributes { get; private set; } = new Dictionary(); + public override string ToString() + { + return Message; + } + /// /// After too much time spent cursing at regexes, here's what I got: /// Parses input string into 'key=value' pair, considerate of quoted (") values. diff --git a/SeeTimeline/LogToEvents.cs b/SeeTimeline/LogToEvents.cs index 5e7b8107..b4a5df1b 100644 --- a/SeeTimeline/LogToEvents.cs +++ b/SeeTimeline/LogToEvents.cs @@ -31,13 +31,14 @@ namespace SeeTimeline public class EventSet { + public const string NoAddress = "-"; + public const string MiscAddress = "~"; + private readonly Dictionary> events = new Dictionary>(); private readonly LogLineAdder adder = new LogLineAdder(); public void Add(string address, CodexEvent e) { - if (address != "-" && (!address.Contains("treeCid:") || !address.Contains("index:"))) return; - if (!events.ContainsKey(address)) events.Add(address, new List()); events[address].Add(e); @@ -54,7 +55,7 @@ namespace SeeTimeline var keys = events.Keys.ToArray(); foreach (var key in keys) { - if (!addresses.Contains(key)) + if (key != NoAddress && key != MiscAddress && !addresses.Contains(key)) { events.Remove(key); } @@ -112,13 +113,15 @@ namespace SeeTimeline public void Parse() { + //if (!line.Attributes.Any(a => a.Value.ToLowerInvariant().Contains("index: 5"))) return; + //AddJobs(result, "Created", Colors.Red, req.Created); // trace "BlockRequest created", address if (line.Message == "BlockRequest created") AddEvent(line.Attributes["address"], "ReqCreated", Colors.Red); //AddJobs(result, "TaskScheduled", Colors.Purple, req.TaskScheduled); // trace "Task scheduled", peerId = task.id - else if (line.Message == "Task scheduled") AddEvent("-", "TaskScheduled", Colors.White); + else if (line.Message == "Task scheduled") AddEvent(EventSet.NoAddress, "TaskScheduled", Colors.Black); //trace "Sending wantHave request", toAsk, peer = p.id //AddJobs(result, "WantHaveSent", Colors.Orange, req.WantHaveSent); @@ -128,9 +131,20 @@ namespace SeeTimeline //AddJobs(result, "WantBlkSent", Colors.Green, req.WantBlkSent); else if (line.Message == "Sending wantBlock request to") AddMultiple(line.Attributes["addresses"], "SentWantBlk", Colors.Green); - //trace "Handling blockPresences", addrs = blocks.mapIt(it.address) + //trace "Handling blockPresences", addrs = blocks.mapIt(it.address), anyCancel = blocks.anyIt(it.isCancel) //AddJobs(result, "PresenceRecv", Colors.Yellow, req.PresenceRecv); - else if (line.Message == "Handling blockPresences") AddMultiple(line.Attributes["addrs"], "PresenceRecv", Colors.Yellow); + else if (line.Message == "Handling blockPresences") + { + var anyCancel = line.Attributes["anyCancel"].ToLowerInvariant(); + if (anyCancel == "true") + { + AddMultiple(line.Attributes["addrs"], "CancelPresenceRecv", Colors.Red); + } + else + { + AddMultiple(line.Attributes["addrs"], "PresenceRecv", Colors.Yellow); + } + } //trace "Sending block request cancellations to peers", addrs, peers = b.peers.mapIt($it.id) //AddJobs(result, "CancelSent", Colors.Purple, req.CancelSent); @@ -169,9 +183,21 @@ namespace SeeTimeline //AddJobs(result, "WantBlkRecv", Colors.Yellow, req.WantBlkRecv); else if (line.Message == "Received wantBlock") AddEvent(line.Attributes["address"], "WantBlkRecv", Colors.Yellow); - //trace "Sending presence to remote", addrs = presence.mapIt(it.address) + //trace "Sending presence to remote", addrs = presence.mapIt(it.address), anyCancel = presence.anyIt(it.isCancel) //AddJobs(result, "PresenceSent", Colors.Orange, req.PresenceSent); - else if (line.Message == "Sending presence") AddMultiple(line.Attributes["addrs"], "PresenceSent", Colors.Orange); + else if (line.Message == "Sending presence") + { + var isCancel = line.Attributes["anyCancel"]; + + if (isCancel.ToLowerInvariant() == "true") + { + AddMultiple(line.Attributes["addrs"], "CancelPresenceSent", Colors.Red); + } + else + { + AddMultiple(line.Attributes["addrs"], "PresenceSent", Colors.Orange); + } + } //trace "Begin sending blocks", addrs = wantAddresses //AddJobs(result, "BlkSendStart", Colors.Green, req.BlkSendStart); @@ -180,6 +206,32 @@ namespace SeeTimeline //trace "Finished sending blocks", addrs = wantAddresses //AddJobs(result, "BlkSendEnd", Colors.Blue, req.BlkSendEnd); else if (line.Message == "Finished sending blocks") AddMultiple(line.Attributes["addrs"], "BlkSendEnd", Colors.Blue); + + else if (line.Message == "tick") AddEvent(EventSet.MiscAddress, "tick", Colors.Black); + + //// Discovery Started + //else if (line.Message == "Discovery Started") AddEvent(EventSet.NoAddress, "DiscoveryStart", Colors.Black); + + //// Setting up peer + //else if (line.Message == "Setting up peer") AddEvent(EventSet.NoAddress, "NewPeer", Colors.Black); + + //// Error block handle, disconnecting peer + //else if (line.Message == "Error block handle, disconnecting peer") AddEvent(EventSet.NoAddress, "DisconnectPeer", Colors.Black); + + //// Dropping peer + //else if (line.Message == "Dropping peer") AddEvent(EventSet.NoAddress, "DisconnectPeer", Colors.Black); + + //// Acquired slot + //else if (line.Message == "Acquired slot") AddEvent(EventSet.MiscAddress, "AcqSlot", Colors.Black); + + //// Released slot + //else if (line.Message == "Released slot") AddEvent(EventSet.MiscAddress, "RlsSlot", Colors.Black); + + //// Got discv5 lookup query response + //else if (line.Message == "Got discv5 lookup query response") AddEvent(EventSet.MiscAddress, "Discv5", Colors.Black); + + //// waiting for data + //else if (line.Message == "waiting for data") AddEvent(EventSet.MiscAddress, "wait", Colors.Black); } private void AddMultiple(string addresses, string name, Color color) diff --git a/SeeTimeline/MainWindow.xaml.cs b/SeeTimeline/MainWindow.xaml.cs index 53faa8d1..11d15404 100644 --- a/SeeTimeline/MainWindow.xaml.cs +++ b/SeeTimeline/MainWindow.xaml.cs @@ -30,11 +30,11 @@ namespace SeeTimeline private void Button_Click(object sender, RoutedEventArgs e) { //var path = "d:\\Projects\\cs-codex-dist-tests\\Tests\\CodexReleaseTests\\bin\\Debug\\net8.0\\CodexTestLogs\\2024-12\\20\\09-57-01Z_TwoClientTests\\"; - var path = "C:\\Projects\\cs-codex-dist-tests\\Tests\\CodexReleaseTests\\bin\\Debug\\net8.0\\CodexTestLogs\\2025-01\\06\\09-45-03Z_TwoClientTests\\"; - var file1 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-14]_000001_Downloader1.log"); - var file2 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-14]_000000_Uploader0.log"); - var file3 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-15]_000001_Downloader1.log"); - var file4 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-15]_000000_Uploader0.log"); + var path = "c:\\Projects\\cs-codex-dist-tests\\Tests\\CodexReleaseTests\\bin\\Debug\\net8.0\\CodexTestLogs\\2025-01\\07\\14-09-39Z_TwoClientTests\\"; + var file1 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-18-f]_000001_Downloader1.log"); + var file2 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-18-f]_000000_Uploader0.log"); + var file3 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-18-s]_000001_Downloader1.log"); + var file4 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-18-s]_000000_Uploader0.log"); Line1Name.Text = file1; Line2Name.Text = file2; @@ -110,17 +110,23 @@ namespace SeeTimeline set.Iterate((addr, events) => { - //result.Add(CreateItem(addr, events)); - foreach (var e in events) + if (addr == EventSet.NoAddress || addr == EventSet.MiscAddress) { - result.Add(new TimelinerItem() + result.Add(CreateItem(addr, events)); + } + else + { + foreach (var e in events) { - Name = addr + " " + e.Name, - Jobs = new List + result.Add(new TimelinerItem() + { + Name = addr + " " + e.Name, + Jobs = new List { CreateJob(e) } - }); + }); + } } }); diff --git a/Tests/CodexReleaseTests/DataTests/TwoClientTest.cs b/Tests/CodexReleaseTests/DataTests/TwoClientTest.cs index 3e5889da..3ceda0a8 100644 --- a/Tests/CodexReleaseTests/DataTests/TwoClientTest.cs +++ b/Tests/CodexReleaseTests/DataTests/TwoClientTest.cs @@ -39,15 +39,23 @@ namespace CodexReleaseTests.DataTests "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-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 )] string img ) { CodexContainerRecipe.DockerImageOverride = img; - var uploader = StartCodex(s => s.WithName("Uploader")); - var downloader = StartCodex(s => s.WithName("Downloader").WithBootstrapNode(uploader)); + var uploader = StartCodex(s => s.WithName("Uploader").WithLogLevel(CodexLogLevel.Trace, new CodexLogCustomTopics(CodexLogLevel.Trace, CodexLogLevel.Trace, CodexLogLevel.Trace))); + var downloader = StartCodex(s => s.WithName("Downloader").WithLogLevel(CodexLogLevel.Trace, new CodexLogCustomTopics(CodexLogLevel.Trace, CodexLogLevel.Trace, CodexLogLevel.Trace)).WithBootstrapNode(uploader)); PerformTwoClientTest(uploader, downloader); } @@ -55,18 +63,60 @@ namespace CodexReleaseTests.DataTests [Test] public void ParseLogs() { - var path = ""; - var lines = File.ReadAllLines(path); + var path = "c:\\Projects\\cs-codex-dist-tests\\Tests\\CodexReleaseTests\\bin\\Debug\\net8.0\\CodexTestLogs\\2025-01\\07\\10-32-44Z_TwoClientTests\\"; + var file1 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-16-f]_000001_Downloader1.log"); + var file2 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-16-f]_000000_Uploader0.log"); + var file3 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-16-s]_000001_Downloader1.log"); + var file4 = Path.Combine(path, "TwoClientTest[thatbenbierens_nim-codex_blkex-cancelpresence-16-s]_000000_Uploader0.log"); + + var lines = File.ReadAllLines(file3); + var clines = new List(); foreach (var line in lines) { var cline = CodexLogLine.Parse(line); - if (cline == null) continue; + if (cline != null) clines.Add(cline); + } - if (cline.Message == "times for") + var gaps = new List(); + for (var i = 0; i < clines.Count; i++) + { + if (i + 1 < clines.Count) { - ProcessTimes(cline); + var line = clines[i]; + var next = clines[i + 1]; + gaps.Add(new Gap(line, next)); } } + + 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)