From 952dfa05ff974a8aa4fcbe1ebcae9da99cefcad4 Mon Sep 17 00:00:00 2001 From: Sipke Schoorstra Date: Fri, 11 Sep 2026 19:01:06 -0700 Subject: [PATCH] feat(bpmn): project interpreter diagnostics onto the scope's execution log (#8058) * feat(bpmn): project interpreter diagnostics onto the scope's execution log Under Option A only bound work carries an activity id, so gateways, events and flows had no per-element trace in the journal. BpmnScopeHost now projects each new BpmnExecutionState.Diagnostics entry onto the scope's own execution log before Prune() runs, keyed by element id, with a persisted high-water mark so a resumed scope never re-emits one. The scope's own start and completion stay out, since they are already journaled as the activity's own lifecycle. Event names and the payload shape are documented as a public compatibility surface for elsa-studio#1000 to mirror. Co-Authored-By: Claude Opus 5 * fix(bpmn): project element and flow diagnostics dropped by the FlowId exclusion The diagnostics exclusion keyed on Kind == TokenEmitted && FlowId is null/empty also dropped an error or cancel boundary's own token emission, since a boundary fires without an inbound flow. Narrow the rule to skip only diagnostics that name neither an element nor a flow -- the scope's own terminal Completed summary -- so every diagnostic keyed on an element or a flow, including a start event's and a boundary's, is projected. Also make DiagnosticSequence resilient: TryParse instead of Parse, logging a warning and skipping projection for an id that doesn't match diag:N rather than faulting the evaluation. Add a reflection-based test that keeps BpmnDiagnosticEventNames in lockstep with BpmnDiagnosticKind, and record the diagnostics volume measurement in the wiki. Co-Authored-By: Claude Opus 5 * fix(bpmn): require exact diag:N ids and seed the diagnostics cursor from prior state Reject any diagnostic id that is not the exact "diag:" prefix followed by a non-negative integer, so a malformed id can no longer poison the durable projection cursor and cause later, genuinely valid, lower-sequence diagnostics to be skipped forever. Also seed a missing cursor from the highest valid sequence in the scope's prior persisted state instead of treating it as zero, so a scope persisted before diagnostics projection existed does not replay every retained historical diagnostic as new on its next evaluation. Co-Authored-By: Claude Opus 5 --------- Co-authored-by: Claude Opus 5 --- doc/wiki/bpmn-workflows.md | 12 ++ .../Hosting/BpmnDiagnosticEventNames.cs | 92 +++++++++++++ .../Hosting/BpmnDiagnosticLogPayload.cs | 25 ++++ .../Hosting/BpmnDiagnosticsCursor.cs | 15 +++ .../Elsa.Bpmn/Hosting/BpmnScopeHost.cs | 120 +++++++++++++++++ .../Elsa.Bpmn/Hosting/BpmnScopeMemory.cs | 3 + .../BpmnDiagnosticsProjectionTests.cs | 122 ++++++++++++++++++ .../Scenarios/HostPort/BpmnTestHost.cs | 17 +++ .../BpmnDiagnosticEventNamesTests.cs | 39 ++++++ .../BpmnScopeHostDiagnosticSequenceTests.cs | 41 ++++++ 10 files changed, 486 insertions(+) create mode 100644 src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticEventNames.cs create mode 100644 src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticLogPayload.cs create mode 100644 src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticsCursor.cs create mode 100644 test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnDiagnosticsProjectionTests.cs create mode 100644 test/unit/Elsa.Bpmn.UnitTests/BpmnDiagnosticEventNamesTests.cs create mode 100644 test/unit/Elsa.Bpmn.UnitTests/BpmnScopeHostDiagnosticSequenceTests.cs diff --git a/doc/wiki/bpmn-workflows.md b/doc/wiki/bpmn-workflows.md index 5d89eeae6..5439ea355 100644 --- a/doc/wiki/bpmn-workflows.md +++ b/doc/wiki/bpmn-workflows.md @@ -126,6 +126,18 @@ The BPMN interpreter's execution state (`BpmnExecutionState`) and the scope's `B Test coverage: `test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnPersistenceTests.cs` proves that state size stays flat across a multi-iteration loop. +## Diagnostics Projection + +Under Option A, only bound work (a task, a nested scope) gets its own Elsa activity id. A gateway, an intermediate event or a sequence flow is a decision the interpreter made internally, and the interpreter records every one of them in `BpmnExecutionState.Diagnostics`. `BpmnScopeHost` projects each new diagnostic onto the scope's own execution log — as an `AddExecutionLogEntry` call on the scope's own `ActivityExecutionContext`, never a child's — before the state is pruned, since pruning caps `Diagnostics` at 200 entries and a diagnostic that falls off the cap can never be projected from persisted state afterward. A resumed scope does not re-project a diagnostic a previous evaluation already turned into a journal entry: the last diagnostic id projected is tracked as a high-water mark in the scope's own memory, next to its execution state and work ledger. + +- **Event name** — the diagnostic kind's own enum member name (e.g. `TokenEmitted`, `Joined`, `Faulted`). `Elsa.Bpmn.Hosting.BpmnDiagnosticEventNames` documents every one of them as a public constant, so Studio has one place to mirror instead of depending on the library's integer enum values. +- **Source** — always `"BPMN"` (`BpmnDiagnosticEventNames.Source`). +- **Payload** — `Elsa.Bpmn.Hosting.BpmnDiagnosticLogPayload`, serialized camelCase like every other execution log payload: `diagnosticId`, `elementId`, `flowId`, `tokenId`, `kind` (the enum member name, again as a string) and `details`, carried verbatim from the diagnostic. Studio keys its overlay on `elementId` (and, for a decision about a flow, `flowId`); neither is folded into the message. +- **Not projected** — only a diagnostic that names neither an element nor a flow, which is the scope's own terminal `Completed` diagnostic; it is already journaled as the activity's own lifecycle. Everything else is projected, including a start event's own token emission (keyed on the start element, which Studio's overlay lights up) and an error or cancel boundary's token emission when it fires without an inbound flow (keyed on the boundary element). +- **Volume** — measured with the 12-iteration sequential multi-instance loop, each iteration after the first adds two projected entries (`Consumed`, `Scheduled`), 106 diagnostics in total, so no per-kind filter is applied beyond the exclusion above; journal growth is proportional to the process's work, like any activity's journal. + +Test coverage: `test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnDiagnosticsProjectionTests.cs`. + ## Composing BPMN Into an Elsa Workflow A `BpmnProcess` is a `Container` and can be nested inside any Elsa composite activity (e.g. a `Flowchart`). The workflow that hosts it is responsible for marking the outermost scope as the entry point (`IsRootScope = true`). Nested BPMN scopes — embedded subprocesses, event subprocesses — are themselves `BpmnProcess` instances bound as child work by the binder and need no special treatment from the containing workflow. diff --git a/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticEventNames.cs b/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticEventNames.cs new file mode 100644 index 000000000..d85e31165 --- /dev/null +++ b/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticEventNames.cs @@ -0,0 +1,92 @@ +namespace Elsa.Bpmn.Hosting; + +/// +/// The stable execution log eventName for each Bpmn.Model.State.BpmnDiagnosticKind, and the +/// source every one of them carries. derives the event name directly from the +/// diagnostic kind's own enum member name; the constants here exist so Studio has one place to mirror them rather +/// than depending on the library's integer enum values. +/// +public static class BpmnDiagnosticEventNames +{ + /// The source every execution log entry projected from a BPMN diagnostic carries. + public const string Source = "BPMN"; + + /// + /// A token arrived at an element via a sequence flow, or an element (a start event, or an error/cancel boundary + /// firing without an inbound flow) emitted a token of its own. Projected by whenever + /// it names an element or a flow, which every one of these does. + /// + public const string TokenEmitted = "TokenEmitted"; + + /// An element started bound work: a single unit, or one instance of a multi-instance loop. + public const string Scheduled = "Scheduled"; + + /// A token arrived at a join and is waiting for its siblings. + public const string Waiting = "Waiting"; + + /// A join fired after its arrivals were satisfied. + public const string Joined = "Joined"; + + /// An end event consumed a token, or a multi-instance loop consumed a finished instance's token. + public const string Consumed = "Consumed"; + + /// A unit of work was cancelled. + public const string Canceled = "Canceled"; + + /// A terminate end event ended the process. + public const string Terminated = "Terminated"; + + /// An element's behavior failed. + public const string BehaviorFailure = "BehaviorFailure"; + + /// + /// The scope itself finished. Never projected by : unlike every other kind, it names + /// neither an element nor a flow, and the scope's own activity lifecycle already journals its completion. + /// + public const string Completed = "Completed"; + + /// A unit of work faulted. + public const string Faulted = "Faulted"; + + /// A host completion carrying an attached compensation boundary registered a compensable. + public const string CompensationRegistered = "CompensationRegistered"; + + /// A compensate throw/end event triggered a compensation replay. + public const string CompensationTriggered = "CompensationTriggered"; + + /// A compensation handler ran to completion for one registered compensable. + public const string Compensated = "Compensated"; + + /// A cancel end event began (or completed) cancelling a transaction scope. + public const string TransactionCancelled = "TransactionCancelled"; + + /// An escalation throw/end event staged an enclosing-scope signal notification. + public const string EscalationRaised = "EscalationRaised"; + + /// An escalation notification matched an attached boundary and fired it. + public const string EscalationCaught = "EscalationCaught"; + + /// An escalation reached a scope that could not catch it; a no-op, never a fault. + public const string EscalationUnhandled = "EscalationUnhandled"; + + /// An interrupting escalation boundary matched a notification whose host had already terminalized; a no-op, never a fault. + public const string EscalationLate = "EscalationLate"; + + /// An event subprocess was activated by its start-event trigger. + public const string EventSubprocessActivated = "EventSubprocessActivated"; + + /// An event subprocess body ran to completion. + public const string EventSubprocessCompleted = "EventSubprocessCompleted"; + + /// A call activity's bound child failed and the engine routed the call-activity failure ladder instead of normal outbound flows. + public const string CallActivityFailureRouted = "CallActivityFailureRouted"; + + /// A message, signal or timer triggered scope listener was armed. + public const string ScopeListenerArmed = "ScopeListenerArmed"; + + /// A message, signal or timer triggered scope listener fired. + public const string ScopeListenerFired = "ScopeListenerFired"; + + /// A message, signal or timer triggered scope listener was retired. + public const string ScopeListenerRetired = "ScopeListenerRetired"; +} diff --git a/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticLogPayload.cs b/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticLogPayload.cs new file mode 100644 index 000000000..f71d8391c --- /dev/null +++ b/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticLogPayload.cs @@ -0,0 +1,25 @@ +namespace Elsa.Bpmn.Hosting; + +/// +/// The payload every execution log entry projects from a BPMN diagnostic carries. +/// +/// +/// This shape is a compatibility surface: Studio's instance viewer overlay reads it to key a decision back onto +/// the BPMN element — and, for a decision about a sequence flow, the flow — it belongs to, since under Option A +/// only bound work has an activity id. carries the diagnostic kind's own enum member name +/// (see ) rather than its integer value, so a Bpmn.Model upgrade that +/// reorders or extends BpmnDiagnosticKind cannot silently change what a reader keyed on the number would see. +/// +/// The diagnostic's id in the interpreter's own pinned id stream (diag:N). +/// The BPMN element the diagnostic is about, or null when it names none. +/// The BPMN sequence flow the diagnostic is about, or null when it names none. +/// The token the diagnostic is about, or null when it names none. +/// The diagnostic kind's enum member name. +/// Free-form key/value details the interpreter attached, carried verbatim. +public sealed record BpmnDiagnosticLogPayload( + string DiagnosticId, + string? ElementId, + string? FlowId, + string? TokenId, + string Kind, + IReadOnlyDictionary Details); diff --git a/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticsCursor.cs b/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticsCursor.cs new file mode 100644 index 000000000..c97ee3e66 --- /dev/null +++ b/src/modules/Elsa.Bpmn/Hosting/BpmnDiagnosticsCursor.cs @@ -0,0 +1,15 @@ +namespace Elsa.Bpmn.Hosting; + +/// +/// The high-water mark of diagnostics a scope has already projected onto its execution log: the numeric ordinal +/// of the last diag:N id it turned into a journal entry. +/// +/// +/// Persisted under , next to +/// and , +/// and serialized the same way. Without it, a scope resumed from persisted state would re-evaluate the same +/// surviving diagnostics Bpmn.Model.State.BpmnExecutionState.Prune carried forward and project every one of +/// them a second time. +/// +/// The ordinal of the last diagnostic id (diag:N) already projected. +internal sealed record BpmnDiagnosticsCursor(int LastSequence); diff --git a/src/modules/Elsa.Bpmn/Hosting/BpmnScopeHost.cs b/src/modules/Elsa.Bpmn/Hosting/BpmnScopeHost.cs index 972aaec2d..16b280df1 100644 --- a/src/modules/Elsa.Bpmn/Hosting/BpmnScopeHost.cs +++ b/src/modules/Elsa.Bpmn/Hosting/BpmnScopeHost.cs @@ -1,4 +1,6 @@ +using System.Globalization; using Bpmn.Model; +using Bpmn.Model.State; using Bpmn.Semantics; using Elsa.Bpmn.Activities; using Elsa.Bpmn.Exceptions; @@ -7,6 +9,7 @@ using Elsa.Extensions; using Elsa.Workflows; using Elsa.Workflows.Activities.Flowchart.Models; using Elsa.Workflows.Signals; +using Microsoft.Extensions.Logging; namespace Elsa.Bpmn.Hosting; @@ -151,6 +154,8 @@ internal sealed class BpmnScopeHost var evaluation = Interpreter.OnWorkFaulted(new BpmnWorkFaultedRequest( Graph, memory.State, Snapshot(memory), record.BindingRef, record.Handle, signal.Exception.Message)); + ProjectDiagnostics(evaluation.State, memory.State); + memory.State = evaluation.State.Prune(); memory.SaveState(); @@ -182,6 +187,12 @@ internal sealed class BpmnScopeHost if (evaluation is null) return; + // Diagnostics are audit-only and capped: projecting from persisted state later would lose whatever + // Prune() already dropped, so this runs on the evaluation's own state, before pruning. memory.State is + // still what was loaded before this evaluation ran -- the prior state -- since it is not overwritten + // until after this call. + ProjectDiagnostics(evaluation.State, memory.State); + // Persist the state before acting on the commands: a command applied against a state that was never // recorded is how a crash produces work with no token behind it. memory.State = evaluation.State.Prune(); @@ -209,6 +220,115 @@ internal sealed class BpmnScopeHost } } + /// + /// Projects every diagnostic the interpreter has appended since the last evaluation onto this scope's own + /// execution log, keyed by element id. Under Option A only bound work has an activity id, so a gateway, an + /// intermediate event or a sequence flow has nothing else in the journal to say where a token went; this is + /// write-only and never read back by the interpreter or this host. + /// + /// + /// Runs on — this scope's own context — and never a child's: the diagnostic describes + /// this scope's decision about a child, and the child may already be torn down by the time this runs. Called + /// with the evaluation's own , before Prune() caps + /// at 200 entries, because projecting from what was actually + /// persisted would lose whatever pruning already dropped. The last diagnostic id it has projected is kept in + /// so a resumed scope does not re-emit one a + /// previous evaluation already turned into a journal entry. + /// + /// The evaluation's own state, not yet pruned. + /// + /// The state this scope had persisted before this evaluation ran, or null for a scope that has never + /// been evaluated before. When the cursor property is absent -- a scope persisted before diagnostics projection + /// existed -- its diagnostics are already accounted for, not new: the cursor is seeded from the highest valid + /// sequence among 's own diagnostics before anything is projected, so only what + /// this evaluation produced gets journaled. A genuinely new scope has no prior state and still starts at zero. + /// + private void ProjectDiagnostics(BpmnExecutionState state, BpmnExecutionState? priorState) + { + var storedCursor = BpmnScopeMemory.Read(_context, BpmnScopeMemory.DiagnosticsCursorPropertyKey)?.LastSequence; + var lastProjectedSequence = storedCursor ?? SeedCursorFrom(priorState); + var highWaterMark = lastProjectedSequence; + + foreach (var diagnostic in state.Diagnostics) + { + if (!TryGetDiagnosticSequence(diagnostic.DiagnosticId, out var sequence)) + { + _context.GetRequiredService>() + .LogWarning("BPMN diagnostic id '{DiagnosticId}' is not in the expected 'diag:N' format and was skipped for projection.", diagnostic.DiagnosticId); + continue; + } + + if (sequence <= lastProjectedSequence) + continue; + + highWaterMark = Math.Max(highWaterMark, sequence); + + // Only a diagnostic that names neither an element nor a flow is scope-level and already journaled as the + // activity's own lifecycle: the terminal "Completed" summary. Everything else -- including a start + // event's own token emission, and a boundary event's token emission when it has no inbound flow (an + // error or cancel boundary fires without one) -- names an element or a flow and is projected. + if (string.IsNullOrEmpty(diagnostic.ElementId) && string.IsNullOrEmpty(diagnostic.FlowId)) + continue; + + var payload = new BpmnDiagnosticLogPayload( + diagnostic.DiagnosticId, + diagnostic.ElementId, + diagnostic.FlowId, + diagnostic.TokenId, + diagnostic.Kind.ToString(), + diagnostic.Details); + + _context.AddExecutionLogEntry(diagnostic.Kind.ToString(), diagnostic.Message, BpmnDiagnosticEventNames.Source, payload); + } + + if (highWaterMark != lastProjectedSequence) + BpmnScopeMemory.Write(_context, BpmnScopeMemory.DiagnosticsCursorPropertyKey, new BpmnDiagnosticsCursor(highWaterMark)); + } + + /// + /// The starting cursor for a scope that has no yet: + /// the highest valid sequence already present in 's diagnostics, or zero when there + /// is no prior state at all. A scope persisted before diagnostics projection existed has diagnostics in its + /// state but no cursor; treating that absence as zero would make its next evaluation journal every one of those + /// already-historical diagnostics as if they were new. + /// + private static int SeedCursorFrom(BpmnExecutionState? priorState) + { + var highest = 0; + + if (priorState is null) + return highest; + + foreach (var diagnostic in priorState.Diagnostics) + { + if (TryGetDiagnosticSequence(diagnostic.DiagnosticId, out var sequence) && sequence > highest) + highest = sequence; + } + + return highest; + } + + /// + /// The numeric ordinal in a diagnostic id (diag:N) — a pure function of the interpreter's own + /// mutation-order sequence, so it sorts the same as arrival order. Never throws: an id that does not match the + /// expected format fails to parse rather than faulting the evaluation, since this runs on every evaluation. + /// + /// + /// Requires the exact ordinal prefix diag: and a non-negative integer suffix with no leading sign, digit + /// grouping or surrounding whitespace: a malformed id that happened to parse as a large number would poison the + /// durable cursor and silently drop every later, genuinely valid, lower-sequence diagnostic forever. + /// + internal static bool TryGetDiagnosticSequence(string diagnosticId, out int sequence) + { + const string prefix = "diag:"; + + if (diagnosticId.StartsWith(prefix, StringComparison.Ordinal)) + return int.TryParse(diagnosticId.AsSpan(prefix.Length), NumberStyles.None, CultureInfo.InvariantCulture, out sequence); + + sequence = 0; + return false; + } + /// /// Finds the unit of work this scope started that the failing activity belongs to, walking outward from the /// failure. diff --git a/src/modules/Elsa.Bpmn/Hosting/BpmnScopeMemory.cs b/src/modules/Elsa.Bpmn/Hosting/BpmnScopeMemory.cs index 853ae31af..730ba9da8 100644 --- a/src/modules/Elsa.Bpmn/Hosting/BpmnScopeMemory.cs +++ b/src/modules/Elsa.Bpmn/Hosting/BpmnScopeMemory.cs @@ -22,6 +22,9 @@ internal sealed class BpmnScopeMemory /// The property key holding this scope's work ledger. public const string WorkLedgerPropertyKey = "Bpmn:WorkLedger"; + /// The property key holding the high-water mark of diagnostics this scope has already projected onto its execution log. + public const string DiagnosticsCursorPropertyKey = "Bpmn:DiagnosticsCursor"; + private static readonly JsonSerializerOptions SerializerOptions = new(JsonSerializerDefaults.General); private readonly ActivityExecutionContext _context; diff --git a/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnDiagnosticsProjectionTests.cs b/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnDiagnosticsProjectionTests.cs new file mode 100644 index 000000000..3c93bf8ef --- /dev/null +++ b/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnDiagnosticsProjectionTests.cs @@ -0,0 +1,122 @@ +using Elsa.Bpmn.Hosting; +using Elsa.Workflows.IncidentStrategies; +using Elsa.Workflows.Models; +using Xunit.Abstractions; + +namespace Elsa.Bpmn.IntegrationTests.Scenarios.HostPort; + +/// +/// D1: the interpreter's BPMN diagnostics are projected onto the scope's own execution log, keyed by element id, so +/// Studio's instance viewer has something to read for a gateway, an intermediate event or a sequence flow — none of +/// which has an activity id of its own under Option A. +/// +public class BpmnDiagnosticsProjectionTests(ITestOutputHelper testOutputHelper) +{ + private readonly BpmnTestHost _host = new(testOutputHelper); + + [Fact(DisplayName = "Diagnostics for a parallel split, both flows and the join are projected onto the scope's own journal, none duplicated after a suspend and a resume")] + public async Task ParallelSplitAndJoin_ProjectsDiagnosticsForTheGatewayAndFlows_WithNoDuplicatesAfterSuspendAndResume() + { + // Arrange & Act: a parallel split into two branches that both block, so the scope suspends mid-way and is + // resumed twice -- once per branch -- round-tripping the workflow state through Elsa's own serializer + // between each step, exactly as a real suspend and resume would. + var entries = new List(); + + entries.AddRange((await _host.RunAsync(BpmnTestProcesses.ParallelSplitAndJoinBlocking(_host.Log))).Journal.WorkflowExecutionLogEntries); + _host.RoundTripStateThroughJson(); + entries.AddRange((await _host.FinishWorkAsync("left")).Journal.WorkflowExecutionLogEntries); + _host.RoundTripStateThroughJson(); + entries.AddRange((await _host.FinishWorkAsync("right")).Journal.WorkflowExecutionLogEntries); + + var payloads = entries + .Where(x => x.Source == BpmnDiagnosticEventNames.Source) + .Select(x => Assert.IsType(x.Payload)) + .ToList(); + + // Assert: the split gateway, both outbound flows and the join each left a trace, keyed by element id (or, + // for a flow, by flow id). + Assert.Contains(payloads, p => p.ElementId == "split"); + Assert.Contains(payloads, p => p.FlowId == "flow-split-left"); + Assert.Contains(payloads, p => p.FlowId == "flow-split-right"); + Assert.Contains(payloads, p => p.ElementId == "join" && p.Kind == BpmnDiagnosticEventNames.Joined); + + // ...and nothing the suspend-and-resume round trip crossed was projected twice: each diagnostic id the + // interpreter ever minted for this scope appears in the merged journal at most once. + var diagnosticIds = payloads.Select(p => p.DiagnosticId).ToList(); + Assert.Equal(diagnosticIds.Distinct().Count(), diagnosticIds.Count); + } + + [Fact(DisplayName = "Only the scope's own completion, which names neither an element nor a flow, is never projected as a diagnostic")] + public async Task Scope_DoesNotProjectItsOwnCompletion() + { + var result = await _host.RunAsync(BpmnTestProcesses.LinearTask(_host.Log)); + + var diagnostics = result.Journal.WorkflowExecutionLogEntries.Where(x => x.Source == BpmnDiagnosticEventNames.Source).ToList(); + + // The scope's own completion carries the "Completed" kind and names neither an element nor a flow... + Assert.DoesNotContain(diagnostics, x => x.EventName == BpmnDiagnosticEventNames.Completed); + + // ...but its own start -- the initial token emitted at the "start" element -- names that element, and unlike + // the scope's completion is projected: it is what Studio's overlay lights up for the start event. + Assert.Contains(diagnostics, x => ((BpmnDiagnosticLogPayload)x.Payload!).ElementId == "start" && x.EventName == BpmnDiagnosticEventNames.TokenEmitted); + + // Sanity: the linear task itself did leave a trace, so the assertions above are not vacuous. + Assert.Contains(diagnostics, x => ((BpmnDiagnosticLogPayload)x.Payload!).ElementId == "only"); + } + + [Fact(DisplayName = "An error boundary's token emission is projected even though it carries no inbound flow")] + public async Task ErrorBoundaryCaught_ProjectsTheBoundarysTokenEmission() + { + var result = await _host.RunAsync(BpmnTestProcesses.ErrorBoundaryCaught(_host.Log), typeof(FaultStrategy)); + + var diagnostics = result.Journal.WorkflowExecutionLogEntries.Where(x => x.Source == BpmnDiagnosticEventNames.Source).ToList(); + + // The boundary fires a token of its own -- no sequence flow feeds it -- so FlowId is null, but it names the + // boundary element, and the previous (over-broad) rule dropped it on that account alone. + Assert.Contains(diagnostics, x => + x.EventName == BpmnDiagnosticEventNames.TokenEmitted && + ((BpmnDiagnosticLogPayload)x.Payload!).ElementId == "oops" && + string.IsNullOrEmpty(((BpmnDiagnosticLogPayload)x.Payload!).FlowId)); + } + + [Fact(DisplayName = "A scope persisted before the diagnostics cursor existed does not replay its historical diagnostics on resume")] + public async Task MissingDiagnosticsCursor_DoesNotReplayDiagnosticsFromBeforeTheSuspend_ButStillProjectsNewOnes() + { + // Arrange & Act: run to a suspend with both branches blocked, so the scope's execution state already + // carries diagnostics for the split and both outbound flows... + var beforeResume = await _host.RunAsync(BpmnTestProcesses.ParallelSplitAndJoinBlocking(_host.Log)); + var historicalDiagnosticIds = beforeResume.Journal.WorkflowExecutionLogEntries + .Where(x => x.Source == BpmnDiagnosticEventNames.Source) + .Select(x => ((BpmnDiagnosticLogPayload)x.Payload!).DiagnosticId) + .ToList(); + Assert.NotEmpty(historicalDiagnosticIds); + + // ...then delete the cursor property, simulating a scope that was suspended before this feature existed: + // diagnostics in its state, but nothing recording how many of them are already journaled. + _host.RemoveDiagnosticsCursor(); + + var afterResume = await _host.FinishWorkAsync("left"); + var resumedDiagnostics = afterResume.Journal.WorkflowExecutionLogEntries + .Where(x => x.Source == BpmnDiagnosticEventNames.Source) + .Select(x => (BpmnDiagnosticLogPayload)x.Payload!) + .ToList(); + + // Assert: none of the diagnostics that were already in the state before this evaluation is projected again... + Assert.DoesNotContain(resumedDiagnostics, p => historicalDiagnosticIds.Contains(p.DiagnosticId)); + + // ...but the diagnostic this evaluation actually produced -- the join now waiting on its left inbound flow + // -- is projected, so the missing cursor did not also make the scope swallow genuinely new diagnostics. + Assert.Contains(resumedDiagnostics, p => p.ElementId == "join" && p.FlowId == "flow-left-join"); + } + + [Fact(DisplayName = "Diagnostics are written on the scope's own activity execution context, never a child's")] + public async Task Diagnostics_AreWrittenOnTheScopesOwnContext() + { + var result = await _host.RunAsync(BpmnTestProcesses.LinearTask(_host.Log)); + + var diagnostics = result.Journal.WorkflowExecutionLogEntries.Where(x => x.Source == BpmnDiagnosticEventNames.Source).ToList(); + + Assert.NotEmpty(diagnostics); + Assert.All(diagnostics, x => Assert.Equal("scope", x.ActivityId)); + } +} diff --git a/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnTestHost.cs b/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnTestHost.cs index e8d38a0db..45e25cebc 100644 --- a/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnTestHost.cs +++ b/test/integration/Elsa.Bpmn.IntegrationTests/Scenarios/HostPort/BpmnTestHost.cs @@ -137,6 +137,23 @@ public sealed class BpmnTestHost JsonSerializer.Deserialize(workLedgerJson) ?? new BpmnWorkLedger()); } + /// + /// Removes the diagnostics cursor from a scope's persisted state, simulating a scope that was suspended before + /// diagnostics projection existed: it carries diagnostics in its execution state, but no + /// property to say how many of them are already + /// journaled. + /// + internal void RemoveDiagnosticsCursor(bool nested = false) + { + var state = _state ?? throw new InvalidOperationException("The workflow has not been run yet."); + var scopeStates = state.ActivityExecutionContexts.Where(x => x.Properties.ContainsKey(BpmnScopeMemory.WorkLedgerPropertyKey)); + var scopeState = nested + ? scopeStates.OrderByDescending(x => x.CallStackDepth).First() + : scopeStates.OrderBy(x => x.CallStackDepth).First(); + + scopeState.Properties.Remove(BpmnScopeMemory.DiagnosticsCursorPropertyKey); + } + private RunWorkflowResult Record(RunWorkflowResult result) { _result = result; diff --git a/test/unit/Elsa.Bpmn.UnitTests/BpmnDiagnosticEventNamesTests.cs b/test/unit/Elsa.Bpmn.UnitTests/BpmnDiagnosticEventNamesTests.cs new file mode 100644 index 000000000..c222e68b3 --- /dev/null +++ b/test/unit/Elsa.Bpmn.UnitTests/BpmnDiagnosticEventNamesTests.cs @@ -0,0 +1,39 @@ +using System.Reflection; +using Bpmn.Model.State; +using Elsa.Bpmn.Hosting; + +namespace Elsa.Bpmn.UnitTests; + +/// +/// mirrors every member of by name so +/// can derive an execution log event name from the enum without depending on the +/// library's integer values. Nothing in the compiler links the two, so a library upgrade that renames or adds a +/// member would drift silently; these tests catch that at build time instead. +/// +public class BpmnDiagnosticEventNamesTests +{ + private static readonly IReadOnlyDictionary EventNameConstants = typeof(BpmnDiagnosticEventNames) + .GetFields(BindingFlags.Public | BindingFlags.Static) + .Where(f => f.IsLiteral && !f.IsInitOnly && f.FieldType == typeof(string) && f.Name != nameof(BpmnDiagnosticEventNames.Source)) + .ToDictionary(f => f.Name, f => (string)f.GetRawConstantValue()!); + + [Fact] + public void EveryDiagnosticKindMember_HasAnIdenticallyNamedConstant() + { + var memberNames = Enum.GetNames(); + + Assert.All(memberNames, name => + { + Assert.True(EventNameConstants.TryGetValue(name, out var value), $"'{name}' has no matching constant in {nameof(BpmnDiagnosticEventNames)}."); + Assert.Equal(name, value); + }); + } + + [Fact] + public void NoConstant_IsNotADiagnosticKindMember() + { + var memberNames = Enum.GetNames().ToHashSet(); + + Assert.All(EventNameConstants.Keys, name => Assert.Contains(name, memberNames)); + } +} diff --git a/test/unit/Elsa.Bpmn.UnitTests/BpmnScopeHostDiagnosticSequenceTests.cs b/test/unit/Elsa.Bpmn.UnitTests/BpmnScopeHostDiagnosticSequenceTests.cs new file mode 100644 index 000000000..1c137da7a --- /dev/null +++ b/test/unit/Elsa.Bpmn.UnitTests/BpmnScopeHostDiagnosticSequenceTests.cs @@ -0,0 +1,41 @@ +using Elsa.Bpmn.Hosting; + +namespace Elsa.Bpmn.UnitTests; + +/// +/// is the only thing standing between an interpreter-minted +/// diagnostic id and the durable cursor uses to avoid re-projecting one twice. A +/// malformed id that parsed anyway -- an arbitrary prefix, or a number the library would never actually mint -- +/// could poison that cursor with a value too high, silently skipping every later, genuinely valid, lower-sequence +/// diagnostic forever. These tests pin down exactly what "parses" means: the ordinal prefix diag:, verbatim, +/// followed by a non-negative integer with no sign, grouping or surrounding whitespace. +/// +public class BpmnScopeHostDiagnosticSequenceTests +{ + [Theory] + [InlineData("diag:5", 5)] + [InlineData("diag:0", 0)] + [InlineData("diag:12345", 12345)] + public void TryGetDiagnosticSequence_WithAWellFormedId_ReturnsItsOrdinal(string diagnosticId, int expectedSequence) + { + var parsed = BpmnScopeHost.TryGetDiagnosticSequence(diagnosticId, out var sequence); + + Assert.True(parsed); + Assert.Equal(expectedSequence, sequence); + } + + [Theory] + [InlineData("999")] + [InlineData("foreign:999")] + [InlineData("diag:-1")] + [InlineData("diag:")] + [InlineData("diag:abc")] + [InlineData("diag: 5")] + public void TryGetDiagnosticSequence_WithAMalformedId_IsRejected(string diagnosticId) + { + var parsed = BpmnScopeHost.TryGetDiagnosticSequence(diagnosticId, out var sequence); + + Assert.False(parsed); + Assert.Equal(0, sequence); + } +}