From 14dcad625edcc62bdcbe714af9deebac81605623 Mon Sep 17 00:00:00 2001 From: mikolaj-milewski Date: Thu, 9 May 2024 16:27:25 +0200 Subject: [PATCH] Debug-time traces for Activites (#26) --- .../Activities/Context/Classes/RootContext.cs | 2 +- .../Context/Classes/SourceNodeContext.cs | 2 +- Core/Stateflows/Activities/Engine/Executor.cs | 119 +++++++++++++++++- .../Activities/Utils/IEnumerableExtensions.cs | 5 + .../Blazor/Server/Blazor.Server/Program.cs | 12 +- 5 files changed, 131 insertions(+), 9 deletions(-) diff --git a/Core/Stateflows/Activities/Context/Classes/RootContext.cs b/Core/Stateflows/Activities/Context/Classes/RootContext.cs index 6467275f..f5909269 100644 --- a/Core/Stateflows/Activities/Context/Classes/RootContext.cs +++ b/Core/Stateflows/Activities/Context/Classes/RootContext.cs @@ -92,7 +92,7 @@ public Dictionary GetStreams(Guid threadId) } } - internal IEnumerable GetStreams(Node node, Guid threadId) + internal IEnumerable GetActivatedStreams(Node node, Guid threadId) { lock (Streams) { diff --git a/Core/Stateflows/Activities/Context/Classes/SourceNodeContext.cs b/Core/Stateflows/Activities/Context/Classes/SourceNodeContext.cs index c848b15c..0d2359ad 100644 --- a/Core/Stateflows/Activities/Context/Classes/SourceNodeContext.cs +++ b/Core/Stateflows/Activities/Context/Classes/SourceNodeContext.cs @@ -15,7 +15,7 @@ internal class SourceNodeContext : NodeContext, ISourceNodeContext public IEnumerable Input #pragma warning disable S2365 // Properties should not make collection or array copies => input ??= Context - .GetStreams(Node, ThreadId) + .GetActivatedStreams(Node, ThreadId) .SelectMany(stream => stream.Tokens) .ToArray(); #pragma warning restore S2365 // Properties should not make collection or array copies diff --git a/Core/Stateflows/Activities/Engine/Executor.cs b/Core/Stateflows/Activities/Engine/Executor.cs index af5c3016..8fdfecb7 100644 --- a/Core/Stateflows/Activities/Engine/Executor.cs +++ b/Core/Stateflows/Activities/Engine/Executor.cs @@ -13,6 +13,7 @@ using Stateflows.Activities.Registration; using Stateflows.Activities.Context.Classes; using Stateflows.Utils; +using Stateflows.Common.Data; namespace Stateflows.Activities.Engine { @@ -518,6 +519,9 @@ public async Task> HandleExceptionAsync(Node node, Exception if (handler != null) { + var exceptionName = exception.GetType().Name; + Trace.WriteLine($"⦗→s⦘ Activity '{node.Graph.Name}': handling '{exceptionName}'"); + var exceptionContext = new ActionContext( context.Context, currentScope, @@ -529,6 +533,8 @@ public async Task> HandleExceptionAsync(Node node, Exception DoHandleOutput(exceptionContext); + ReportExceptionHandled(node, exceptionName, exceptionContext.OutputTokens.Where(t => t.Name != TokenInfo.Name).ToArray()); + return exceptionContext.OutputTokens; } @@ -548,7 +554,7 @@ public async Task DoHandleNodeAsync(Node node, NodeScope nodeScope, IEnumerable< { lock (node) { - streams = Context.GetStreams(node, nodeScope.ThreadId); + streams = Context.GetActivatedStreams(node, nodeScope.ThreadId); } } @@ -583,16 +589,19 @@ public async Task DoHandleNodeAsync(Node node, NodeScope nodeScope, IEnumerable< { Inspector.AcceptEventsPlugin.RegisterAcceptEventNode(node, nodeScope.ThreadId); + if (Debugger.IsAttached) + { + Trace.WriteLine($"⦗→s⦘ Activity '{node.Graph.Name}': AcceptEvent node '{node.Name}' registered and waiting for event"); + } + return; } - var inputTokens = input ?? streams.SelectMany(stream => stream.Tokens).ToArray(); + var inputTokens = input ?? streams.GetTokens(); + + ReportNodeExecuting(node, inputTokens); nodeScope = nodeScope.CreateChildScope(node); - lock (node.Graph) - { - Debug.WriteLine($">>> Executing node {node.Name}, threadId: {nodeScope.ThreadId}"); - } var actionContext = new ActionContext(Context, nodeScope, node, inputTokens, selectionTokens); @@ -634,6 +643,8 @@ public async Task DoHandleNodeAsync(Node node, NodeScope nodeScope, IEnumerable< outputTokens = actionContext.OutputTokens.ToList(); } + ReportNodeExecuted(node, outputTokens.Where(t => t.Name != TokenInfo.Name).ToArray()); + if ( StructuralTypes.Contains(node.Type) && ( @@ -675,6 +686,102 @@ public async Task DoHandleNodeAsync(Node node, NodeScope nodeScope, IEnumerable< } } } + else + { + ReportNodeAttemptedExecution(node, streams); + } + } + + private static void ReportNodeExecuting(Node node, IEnumerable inputTokens) + { + if (Debugger.IsAttached) + { + lock (node.Graph) + { + Trace.WriteLine($"⦗→s⦘ Activity '{node.Graph.Name}': executing '{node.Name}'{(!inputTokens.Any() ? ", no input" : "")}"); + ReportTokens(inputTokens); + } + } + } + + private static void ReportNodeExecuted(Node node, IEnumerable outputTokens) + { + if (Debugger.IsAttached) + { + lock (node.Graph) + { + Trace.WriteLine($"⦗→s⦘ Activity '{node.Graph.Name}': executed '{node.Name}'{(!outputTokens.Any() ? ", no output" : "")}"); + ReportTokens(outputTokens, false); + } + } + } + + private static void ReportExceptionHandled(Node node, string exceptionName, IEnumerable outputTokens) + { + if (Debugger.IsAttached) + { + lock (node.Graph) + { + Trace.WriteLine($"⦗→s⦘ Activity '{node.Graph.Name}': '{exceptionName}' handled{(!outputTokens.Any() ? ", no output" : "")}"); + ReportTokens(outputTokens, false); + } + } + } + + private static void ReportNodeAttemptedExecution(Node node, IEnumerable streams) + { + if (Debugger.IsAttached) + { + lock (node.Graph) + { + Trace.WriteLine($"⦗→s⦘ Activity '{node.Graph.Name}': omitting '{node.Name}'"); + ReportTokens(streams.GetTokens()); + var activatedFlows = streams.Select(s => s.EdgeIdentifier).ToArray(); + var missingFlows = node.IncomingEdges.Where(e => !activatedFlows.Contains(e.Identifier)); + ReportMissingFlows(missingFlows); + } + } + } + + private static void ReportTokens(IEnumerable inputTokens, bool input = true) + { + var inputDigest = inputTokens + .GroupBy(t => t.Name) + .Select(g => new + { + Name = g.Key, + Count = g.Count() + }) + .OrderBy(d => d.Name); + + if (inputDigest.Any()) + { + Trace.WriteLine($" {(input ? "Input" : "Output")} (with count):"); + foreach (var digest in inputDigest) + { + Trace.WriteLine($" - '{digest.Name}' ({digest.Count})"); + } + } + } + + private static void ReportMissingFlows(IEnumerable flows) + { + if (flows.Any()) + { + Trace.WriteLine($" Not activated incoming flows:"); + foreach (var flow in flows) + { + var tokenName = flow.TargetTokenType.GetTokenName(); + if (tokenName == TokenInfo.Name) + { + Trace.WriteLine($" - control flow from '{flow.SourceName}' "); + } + else + { + Trace.WriteLine($" - '{tokenName}' from '{flow.SourceName}' "); + } + } + } } private void DoHandleOutput(ActionContext context) diff --git a/Core/Stateflows/Activities/Utils/IEnumerableExtensions.cs b/Core/Stateflows/Activities/Utils/IEnumerableExtensions.cs index 31d13bf5..fb875ef9 100644 --- a/Core/Stateflows/Activities/Utils/IEnumerableExtensions.cs +++ b/Core/Stateflows/Activities/Utils/IEnumerableExtensions.cs @@ -1,6 +1,8 @@ using System; using System.Linq; using System.Collections.Generic; +using Stateflows.Common; +using Stateflows.Activities.Streams; namespace Stateflows.Utils { @@ -42,5 +44,8 @@ public static IEnumerable> Partition(this IEnumerable seque yield return partition; } } + + public static Token[] GetTokens(this IEnumerable streams) + => streams.SelectMany(stream => stream.Tokens).ToArray(); } } diff --git a/Examples/Blazor/Server/Blazor.Server/Program.cs b/Examples/Blazor/Server/Blazor.Server/Program.cs index f84d5ae8..0697d285 100644 --- a/Examples/Blazor/Server/Blazor.Server/Program.cs +++ b/Examples/Blazor/Server/Blazor.Server/Program.cs @@ -80,9 +80,11 @@ .AddExceptionHandler(async c => { Debug.WriteLine(c.Exception.Message); + c.Output(new Token() { Payload = 666 }); }) .AddInitial(b => b .AddControlFlow("action1") + .AddControlFlow("action3") ) .AddAction( "action1", @@ -96,9 +98,17 @@ { Debug.WriteLine(c.Input.OfType>().First().Payload); throw new Exception("test"); - } + }, + b => b.AddControlFlow("action3") + ) + .AddAction( + "action3", + async c => { } ) + + .AddFlow>("action4") ) + .AddAction("action4", async c => { }) ) .AddActivity("activity3")