diff --git a/src/EventTests/Daemon/ShardFailureTests.cs b/src/EventTests/Daemon/ShardFailureTests.cs new file mode 100644 index 0000000..531807e --- /dev/null +++ b/src/EventTests/Daemon/ShardFailureTests.cs @@ -0,0 +1,427 @@ +using JasperFx; +using JasperFx.Core; +using JasperFx.Core.Reflection; +using JasperFx.Events; +using JasperFx.Events.Daemon; +using JasperFx.Events.Projections; +using Microsoft.Extensions.Logging.Abstractions; +using NSubstitute; +using Shouldly; + +namespace EventTests.Daemon; + +// jasperfx#565: a shard that pauses on a poison event used to tell an external supervisor nothing but +// AgentStatus.Paused. ISubscriptionAgent had no reason accessor and ShardStateTracker kept its +// current-state map private, so Wolverine's EventSubscriptionAgent (and CritterWatch behind it) could see +// that progress had flatlined but never why — and the operator response is completely different per cause. +// These tests pin the classification, the agent/tracker surface that exposes it, and the dead-letter +// correlation. +public class ShardFailureTests +{ + private static readonly DateTimeOffset Now = new(2026, 7, 25, 12, 0, 0, TimeSpan.Zero); + + private static Event anEvent(long sequence = 42) => new(new AEvent()) + { + Id = Guid.NewGuid(), + Sequence = sequence, + Version = 3, + StreamId = Guid.NewGuid(), + TenantId = "tenant1", + EventTypeName = "a_event" + }; + + #region classification + + [Fact] + public void classifies_an_apply_event_exception_and_names_the_event() + { + var @event = anEvent(); + var failure = ShardFailure.For(new ApplyEventException(@event, new DivideByZeroException("boom")), Now); + + failure.Category.ShouldBe(ShardFailureCategory.ApplyEvent); + failure.OccurredAt.ShouldBe(Now); + + // The outermost type is what the daemon caught; the root is the one an operator greps for, and is + // the same choice DeadLetterEvent.ExceptionType makes. + failure.ExceptionType.ShouldBe(typeof(ApplyEventException).FullNameInCode()); + failure.RootExceptionType.ShouldBe(typeof(DivideByZeroException).FullNameInCode()); + + failure.Event.ShouldNotBeNull(); + failure.Event.Sequence.ShouldBe(42); + failure.Event.EventId.ShouldBe(@event.Id); + failure.Event.EventTypeName.ShouldBe("a_event"); + failure.Event.StreamId.ShouldBe(@event.StreamId); + failure.Event.StreamKey.ShouldBeNull(); // a Guid-identified stream has no key + failure.Event.TenantId.ShouldBe("tenant1"); + failure.Event.Version.ShouldBe(3); + } + + [Fact] + public void normalizes_the_unused_half_of_the_stream_identity() + { + // A string-keyed stream reports StreamId as Guid.Empty. Rendering that to an operator as + // "stream 00000000-0000-0000-0000-000000000000" is worse than saying nothing. + var @event = anEvent(); + @event.StreamId = Guid.Empty; + @event.StreamKey = "trip-1"; + + var failure = ShardFailure.For(new ApplyEventException(@event, new Exception("boom")), Now); + + failure.Event!.StreamId.ShouldBeNull(); + failure.Event.StreamKey.ShouldBe("trip-1"); + } + + [Fact] + public void classifies_a_store_serialization_failure_from_its_own_declared_category() + { + // The store owns this exception (Marten's EventDeserializationFailureException, Polecat's + // equivalent) and declares its own category — the daemon never sniffs type names. A failure + // detected while READING a row knows only the sequence and the stored type alias, which is + // exactly why every member but Sequence is nullable. + var failure = ShardFailure.For( + new FakeStoreEventFailure(ShardFailureCategory.EventSerialization, 77, "trip_started", + new FormatException("unexpected token")), Now); + + failure.Category.ShouldBe(ShardFailureCategory.EventSerialization); + failure.Event.ShouldNotBeNull(); + failure.Event.Sequence.ShouldBe(77); + failure.Event.EventTypeName.ShouldBe("trip_started"); + failure.Event.EventId.ShouldBeNull(); + failure.Event.StreamId.ShouldBeNull(); + failure.Event.TenantId.ShouldBeNull(); + failure.Event.Version.ShouldBeNull(); + } + + [Fact] + public void classifies_an_unknown_event_type_separately_from_serialization() + { + // Different operator action entirely: a missing registration or a rollback, not bad data. + var failure = ShardFailure.For( + new FakeStoreEventFailure(ShardFailureCategory.UnknownEventType, 9, "trip_ended", null), Now); + + failure.Category.ShouldBe(ShardFailureCategory.UnknownEventType); + failure.Event!.Sequence.ShouldBe(9); + } + + [Fact] + public void classifies_an_out_of_order_progression() + { + // The daemon STOPS rather than pauses on this one, and no single event is to blame. + var failure = ShardFailure.For(new ProgressionProgressOutOfOrderException("Trip", 100, 90), Now); + + failure.Category.ShouldBe(ShardFailureCategory.ProgressionOutOfOrder); + failure.Event.ShouldBeNull(); + } + + [Fact] + public void everything_else_is_other_with_no_event() + { + var failure = ShardFailure.For(new TimeoutException("the database went away"), Now); + + failure.Category.ShouldBe(ShardFailureCategory.Other); + failure.Event.ShouldBeNull(); + failure.Message.ShouldBe("the database went away"); + } + + [Fact] + public void finds_the_failing_event_through_a_wrapping_exception() + { + // The per-event exceptions routinely arrive wrapped — SubscriptionAgent.StopAndDrainAsync throws + // ShardStopException around whatever it caught. A wrapper must not degrade the classification to + // "Other", which is the whole point of walking the graph. + var inner = new ApplyEventException(anEvent(51), new InvalidOperationException("nope")); + var failure = ShardFailure.For(new ShardStopException("Trip:All", inner), Now); + + failure.Category.ShouldBe(ShardFailureCategory.ApplyEvent); + failure.Event!.Sequence.ShouldBe(51); + failure.ExceptionType.ShouldBe(typeof(ShardStopException).FullNameInCode()); + failure.RootExceptionType.ShouldBe(typeof(InvalidOperationException).FullNameInCode()); + } + + [Fact] + public void an_aggregate_of_apply_failures_reports_the_lowest_sequence() + { + // A batch can fail on several events at once. The shard stops at the earliest one, so that is the + // event an operator needs to fix first; the rest are still in Detail. + var aggregate = new AggregateException( + new ApplyEventException(anEvent(90), new Exception("third")), + new ApplyEventException(anEvent(60), new Exception("first")), + new ApplyEventException(anEvent(75), new Exception("second"))); + + var failure = ShardFailure.For(aggregate, Now); + + failure.Category.ShouldBe(ShardFailureCategory.ApplyEvent); + failure.Event!.Sequence.ShouldBe(60); + } + + [Fact] + public void an_aggregate_with_no_event_failure_still_finds_a_progression_conflict() + { + var aggregate = new AggregateException( + new TimeoutException("timeout"), + new ProgressionProgressOutOfOrderException("Trip", 100, 90)); + + ShardFailure.For(aggregate, Now).Category.ShouldBe(ShardFailureCategory.ProgressionOutOfOrder); + } + + [Fact] + public void detail_is_the_full_exception_text() + { + // ShardState.PauseReason has always been ex.ToString(); nothing an operator could read before may + // be lost by routing it through ShardFailure. + var ex = new ApplyEventException(anEvent(), new DivideByZeroException("boom")); + var failure = ShardFailure.For(ex, Now); + + failure.Detail.ShouldBe(ex.ToString()); + failure.Message.ShouldBe(ex.Message); + } + + #endregion + + #region the agent surface + + [Fact] + public async Task a_paused_agent_exposes_the_classified_reason() + { + await using var harness = new AgentHarness(); + + await harness.Agent.ReportCriticalFailureAsync( + new ApplyEventException(anEvent(31), new DivideByZeroException("boom"))); + + harness.Agent.Status.ShouldBe(AgentStatus.Paused); + + // THE issue: Status alone said "paused" and the supervisor had to guess. + var failure = harness.Agent.Failure.ShouldNotBeNull(); + failure.Category.ShouldBe(ShardFailureCategory.ApplyEvent); + failure.Event!.Sequence.ShouldBe(31); + } + + [Fact] + public async Task a_stopped_on_progression_conflict_agent_exposes_its_own_category() + { + await using var harness = new AgentHarness(); + + await harness.Agent.ReportCriticalFailureAsync(new ProgressionProgressOutOfOrderException("Trip", 10, 5)); + + harness.Agent.Status.ShouldBe(AgentStatus.Stopped); + harness.Agent.Failure!.Category.ShouldBe(ShardFailureCategory.ProgressionOutOfOrder); + } + + [Fact] + public async Task the_failure_rides_along_on_the_published_shard_state() + { + await using var harness = new AgentHarness(); + + await harness.Agent.ReportCriticalFailureAsync( + new ApplyEventException(anEvent(31), new DivideByZeroException("boom"))); + + await harness.Tracker.Complete(); + + var state = harness.Tracker.CurrentState("Trip:All").ShouldNotBeNull(); + state.Action.ShouldBe(ShardAction.Paused); + state.Failure!.Category.ShouldBe(ShardFailureCategory.ApplyEvent); + state.Failure.Event!.Sequence.ShouldBe(31); + + // The pre-existing string surface keeps carrying the same full text it always did. + state.PauseReason.ShouldBe(state.Failure.Detail); + state.Exception.ShouldBeOfType(); + } + + [Fact] + public async Task starting_clears_a_stale_failure() + { + // Otherwise a supervisor polling the agent keeps alerting on a failure the operator already fixed. + await using var harness = new AgentHarness(); + + await harness.Agent.ReportCriticalFailureAsync(new TimeoutException("boom")); + harness.Agent.Failure.ShouldNotBeNull(); + + await harness.Agent.StartAsync(new SubscriptionExecutionRequest(0, ShardExecutionMode.Continuous, + new ErrorHandlingOptions(), Substitute.For())); + + harness.Agent.Failure.ShouldBeNull(); + } + + [Fact] + public void an_agent_that_does_not_track_failures_is_unaffected() + { + // The property is a default interface member precisely so wrappers and test doubles compile + // unchanged; a substitute reports null rather than failing to implement anything. + Substitute.For().Failure.ShouldBeNull(); + } + + #endregion + + #region the tracker snapshot + + [Fact] + public async Task the_tracker_hands_out_a_synchronous_snapshot() + { + // Before this the only public surface was Subscribe (you had to be listening BEFORE the transition) + // or a blocking wait. An external poller on its own schedule had nothing to read. + var tracker = new ShardStateTracker(new NulloLogger()); + + try + { + tracker.CurrentState("Trip:All").ShouldBeNull(); + tracker.TryGetCurrentState("Trip:All", out _).ShouldBeFalse(); + + await tracker.PublishAsync(new ShardState("Trip:All", 30) { AgentStatus = "Running" }); + await tracker.PublishAsync(new ShardState("Other:All", 12) { AgentStatus = "Running" }); + + // The snapshot is only as current as the tracker's publication loop, so poll it rather than + // assuming a posted state has already been consumed. (WaitForShardState is no good here: it + // checks the map once and then waits for the NEXT publication, so a state consumed in between + // is missed — and Complete() would close the block for the rest of the test.) + await waitForCurrent(tracker, "Trip:All", 30); + await waitForCurrent(tracker, "Other:All", 12); + + tracker.CurrentState(new ShardName("Trip"))!.Sequence.ShouldBe(30); + tracker.TryGetCurrentState("Trip:All", out var found).ShouldBeTrue(); + found!.Sequence.ShouldBe(30); + + tracker.CurrentStates().Select(x => x.ShardName).OrderBy(x => x) + .ShouldBe(["Other:All", "Trip:All"]); + + // Latest publication per shard wins + await tracker.PublishAsync(new ShardState("Trip:All", 45) { AgentStatus = "Running" }); + (await waitForCurrent(tracker, "Trip:All", 45)).Sequence.ShouldBe(45); + } + finally + { + tracker.As().Dispose(); + } + } + + private static async Task waitForCurrent(ShardStateTracker tracker, string shardName, long sequence) + { + var deadline = DateTimeOffset.UtcNow.AddSeconds(10); + while (DateTimeOffset.UtcNow < deadline) + { + var state = tracker.CurrentState(shardName); + if (state != null && state.Sequence >= sequence) return state; + + await Task.Delay(10); + } + + throw new TimeoutException($"{shardName} never reached sequence {sequence} in the tracker's snapshot"); + } + + #endregion + + #region dead letter correlation + + [Fact] + public void a_dead_letter_gets_its_identity_at_construction() + { + // Assigned here rather than by the store's document identity generation, so the id is known to the + // process that created it before the background, retried write lands. + var deadLetter = new DeadLetterEvent(anEvent(), new ShardName("Trip"), + new ApplyEventException(anEvent(), new Exception("boom"))); + + deadLetter.Id.ShouldNotBe(Guid.Empty); + new DeadLetterEvent(anEvent(), new ShardName("Trip"), + new ApplyEventException(anEvent(), new Exception("boom"))).Id + .ShouldNotBe(deadLetter.Id); + } + + [Fact] + public void a_dead_letter_correlates_with_the_failure_for_the_same_event() + { + var shard = new ShardName("Trip"); + var @event = anEvent(88); + var applyError = new ApplyEventException(@event, new Exception("boom")); + + var deadLetter = new DeadLetterEvent(@event, shard, applyError); + var failure = ShardFailure.For(applyError, Now); + + deadLetter.DescribesSameFailureAs(shard, failure).ShouldBeTrue(); + + // ... and does not claim failures it has nothing to do with + deadLetter.DescribesSameFailureAs(new ShardName("Other"), failure).ShouldBeFalse(); + deadLetter.DescribesSameFailureAs(shard, + ShardFailure.For(new ApplyEventException(anEvent(89), new Exception("boom")), Now)).ShouldBeFalse(); + deadLetter.DescribesSameFailureAs(shard, ShardFailure.For(new TimeoutException("boom"), Now)) + .ShouldBeFalse(); + } + + [Fact] + public void an_unknown_tenant_does_not_veto_a_correlation() + { + // A serialization failure caught while reading the row may not know the tenant. The sequence + // already established the match; a null tenant must not throw it away. + var shard = new ShardName("Trip"); + var deadLetter = new DeadLetterEvent(anEvent(88), shard, + new ApplyEventException(anEvent(88), new Exception("boom"))); + + var failure = ShardFailure.For( + new FakeStoreEventFailure(ShardFailureCategory.EventSerialization, 88, "a_event", null), Now); + + failure.Event!.TenantId.ShouldBeNull(); + deadLetter.DescribesSameFailureAs(shard, failure).ShouldBeTrue(); + } + + [Fact] + public void a_different_tenant_on_the_same_sequence_is_not_a_match() + { + // Under per-tenant event partitioning sequences are per tenant, so the same number is a different + // event in a different tenant. + var shard = new ShardName("Trip"); + var @event = anEvent(88); + var deadLetter = new DeadLetterEvent(@event, shard, new ApplyEventException(@event, new Exception("boom"))); + + var otherTenantEvent = anEvent(88); + otherTenantEvent.TenantId = "tenant2"; + + deadLetter.DescribesSameFailureAs(shard, + ShardFailure.For(new ApplyEventException(otherTenantEvent, new Exception("boom")), Now)) + .ShouldBeFalse(); + } + + #endregion + + // Stands in for a store-owned exception (Marten's EventDeserializationFailureException, + // UnknownEventTypeException, and Polecat's equivalents). Deliberately minimal: it demonstrates the + // whole contract those stores have to satisfy — declare a category, report a sequence, and supply + // whatever else happens to be known. + private sealed class FakeStoreEventFailure : Exception, IEventFailureContext + { + public FakeStoreEventFailure(ShardFailureCategory category, long sequence, string eventTypeName, + Exception? innerException) + : base($"Failure on sequence {sequence} for event type {eventTypeName}", innerException) + { + Category = category; + Sequence = sequence; + EventTypeName = eventTypeName; + } + + public ShardFailureCategory Category { get; } + public long Sequence { get; } + public string? EventTypeName { get; } + public Guid? EventId => null; + public Guid? StreamId => null; + public string? StreamKey => null; + public string? TenantId => null; + public long? Version => null; + } + + private sealed class AgentHarness : IAsyncDisposable + { + public AgentHarness() + { + Tracker = new ShardStateTracker(new NulloLogger()); + Agent = new SubscriptionAgent(new ShardName("Trip"), new AsyncOptions(), TimeProvider.System, + Substitute.For(), Substitute.For(), Tracker, + Substitute.For(), NullLogger.Instance); + } + + public ShardStateTracker Tracker { get; } + public SubscriptionAgent Agent { get; } + + public ValueTask DisposeAsync() + { + Tracker.As().Dispose(); + return ValueTask.CompletedTask; + } + } +} diff --git a/src/JasperFx.Events/Daemon/ApplyEventException.cs b/src/JasperFx.Events/Daemon/ApplyEventException.cs index c2889d2..12ce02b 100644 --- a/src/JasperFx.Events/Daemon/ApplyEventException.cs +++ b/src/JasperFx.Events/Daemon/ApplyEventException.cs @@ -1,6 +1,12 @@ namespace JasperFx.Events.Daemon; -public class ApplyEventException: Exception +/// +/// Thrown when user projection or subscription code fails while applying a single event — the classic +/// "poison pill". Carries the offending event, which is what lets both the +/// dead-letter path and (jasperfx#565) the pause +/// reporting name it. +/// +public class ApplyEventException: Exception, IEventFailureContext { public ApplyEventException(IEvent @event, Exception innerException): base( $"Failure to apply event #{@event.Sequence} Id({@event.Id})", innerException) @@ -9,4 +15,22 @@ public ApplyEventException(IEvent @event, Exception innerException): base( } public IEvent Event { get; } + + ShardFailureCategory IEventFailureContext.Category => ShardFailureCategory.ApplyEvent; + + long IEventFailureContext.Sequence => Event.Sequence; + + string? IEventFailureContext.EventTypeName => Event.EventTypeName; + + Guid? IEventFailureContext.EventId => Event.Id; + + // Guid.Empty is how a string-keyed stream reports "no Guid id", and an empty key is the mirror image + // on a Guid-keyed stream. Normalize both away so a consumer never renders a meaningless value. + Guid? IEventFailureContext.StreamId => Event.StreamId == Guid.Empty ? null : Event.StreamId; + + string? IEventFailureContext.StreamKey => string.IsNullOrEmpty(Event.StreamKey) ? null : Event.StreamKey; + + string? IEventFailureContext.TenantId => Event.TenantId; + + long? IEventFailureContext.Version => Event.Version; } diff --git a/src/JasperFx.Events/Daemon/DeadLetterEvent.cs b/src/JasperFx.Events/Daemon/DeadLetterEvent.cs index 77f80a7..57e4a9a 100644 --- a/src/JasperFx.Events/Daemon/DeadLetterEvent.cs +++ b/src/JasperFx.Events/Daemon/DeadLetterEvent.cs @@ -5,14 +5,21 @@ namespace JasperFx.Events.Daemon; public class DeadLetterEvent { -#pragma warning disable CS8618 +#pragma warning disable CS8618 public DeadLetterEvent() -#pragma warning restore CS8618 +#pragma warning restore CS8618 { } public DeadLetterEvent(IEvent e, ShardName shardName, ApplyEventException ex) { + // jasperfx#565: assign the identity here rather than leaving it to the store's document identity + // generation, so the id of a dead letter is known to the process that created it BEFORE the + // (background, retried) write lands. Stores only generate an id when the value is empty, so + // pre-assigning changes nothing about how the row is persisted. Version 7 keeps the ids + // time-ordered, which is what the store's index would have wanted anyway. + Id = Guid.CreateVersion7(); + ProjectionName = shardName.Name; ShardName = shardName.ShardKey; Timestamp = DateTimeOffset.UtcNow; @@ -42,6 +49,34 @@ public DeadLetterEvent(IEvent e, ShardName shardName, ApplyEventException ex) /// public string? TenantId { get; set; } + /// + /// jasperfx#565: does this dead letter describe the same failing event as + /// on the shard named by ? + /// + /// + /// This is the traceability link between the two halves of a per-event failure, which are recorded on + /// different paths and never at the same time. A shard that PAUSES (the error options do not skip) + /// reports a and writes nothing here — the event was not skipped, so + /// inflating the dead-letter counts stores use as their "projection is unhealthy" signal would be a + /// lie, and a restart loop would rewrite the row on every attempt. A shard that SKIPS + /// ( and friends) writes a dead letter and keeps + /// running. Same event, same projection, same shard, same sequence, same tenant — so an operator (or + /// CritterWatch) that has one can find the other, whether the deployment flipped the skip flag after + /// the pause or the other way round. + /// + /// + public bool DescribesSameFailureAs(ShardName shardName, ShardFailure failure) + { + if (failure.Event == null) return false; + + return ProjectionName == shardName.Name + && ShardName == shardName.ShardKey + && EventSequence == failure.Event.Sequence + // A failure detected before the event materialized may not know its tenant; don't let that + // veto a match the sequence already established. + && (failure.Event.TenantId == null || TenantId == null || TenantId == failure.Event.TenantId); + } + public override string ToString() { return diff --git a/src/JasperFx.Events/Daemon/EventFailureDetails.cs b/src/JasperFx.Events/Daemon/EventFailureDetails.cs new file mode 100644 index 0000000..472dbc6 --- /dev/null +++ b/src/JasperFx.Events/Daemon/EventFailureDetails.cs @@ -0,0 +1,102 @@ +namespace JasperFx.Events.Daemon; + +/// +/// jasperfx#565: the identity of the single event that broke a shard, lifted off an exception into a +/// plain, serializable value. External supervisors (Wolverine's assignment plane, CritterWatch) ship +/// this over a wire and render it in a UI, which an can't reliably do — and an +/// exception also drags along whatever object graph its data referenced. +/// +/// +/// Every member except is nullable: a serialization failure is raised while +/// reading a row, before there is an , so it may know only the sequence and the +/// stored type alias. See . +/// +/// +/// +/// plus the owning shard is also the correlation key to a +/// row: nothing is written to the dead-letter table when a shard PAUSES +/// (a paused event was not skipped), but if the same event is later skipped — +/// and friends — its dead letter carries the same +/// projection name, shard key, sequence and tenant, so a consumer can line the two up. +/// +/// +public record EventFailureDetails +{ + /// + /// Store-wide sequence number of the failing event. + /// + public required long Sequence { get; init; } + + /// + /// The event store's type alias for the failing event (e.g. trip_started), if known. + /// + public string? EventTypeName { get; init; } + + /// + /// Unique id of the failing event, if known. + /// + public Guid? EventId { get; init; } + + /// + /// Stream id of the failing event for Guid-identified streams, if known. + /// + public Guid? StreamId { get; init; } + + /// + /// Stream key of the failing event for string-identified streams, if known. + /// + public string? StreamKey { get; init; } + + /// + /// Tenant of the failing event, if known. + /// + public string? TenantId { get; init; } + + /// + /// Version of the failing event within its stream, if known. + /// + public long? Version { get; init; } + + /// + /// Lift the failing event's identity off an exception that knows it. + /// + public static EventFailureDetails From(IEventFailureContext context) + { + return new EventFailureDetails + { + Sequence = context.Sequence, + EventTypeName = context.EventTypeName, + EventId = context.EventId, + StreamId = context.StreamId, + StreamKey = context.StreamKey, + TenantId = context.TenantId, + Version = context.Version + }; + } + + /// + /// Lift the identity off a fully materialized event. + /// + public static EventFailureDetails From(IEvent @event) + { + return new EventFailureDetails + { + Sequence = @event.Sequence, + EventTypeName = @event.EventTypeName, + EventId = @event.Id, + // Guid.Empty is how a string-keyed stream reports "no Guid id", and vice versa. Normalize + // both to null so a consumer never renders a meaningless Guid.Empty or an empty key. + StreamId = @event.StreamId == Guid.Empty ? null : @event.StreamId, + StreamKey = string.IsNullOrEmpty(@event.StreamKey) ? null : @event.StreamKey, + TenantId = @event.TenantId, + Version = @event.Version + }; + } + + public override string ToString() + { + var stream = StreamId?.ToString() ?? StreamKey; + return + $"event #{Sequence}{(EventTypeName == null ? "" : $" ({EventTypeName})")}{(stream == null ? "" : $" on stream {stream}")}{(TenantId == null ? "" : $" for tenant '{TenantId}'")}"; + } +} diff --git a/src/JasperFx.Events/Daemon/IEventFailureContext.cs b/src/JasperFx.Events/Daemon/IEventFailureContext.cs new file mode 100644 index 0000000..e1710c6 --- /dev/null +++ b/src/JasperFx.Events/Daemon/IEventFailureContext.cs @@ -0,0 +1,67 @@ +namespace JasperFx.Events.Daemon; + +/// +/// jasperfx#565: implemented by any exception that can name the single event it failed on, so the daemon +/// can classify a shard failure and report the offending event WITHOUT knowing the concrete exception +/// types of the store underneath it. +/// +/// +/// JasperFx.Events owns only one of these — . The others live in the +/// stores, because that is where events are read and deserialized: Marten's +/// EventDeserializationFailureException / UnknownEventTypeException and Polecat's +/// equivalents implement this interface and declare their own . That is +/// deliberately the store's call rather than type-name sniffing in the daemon. +/// +/// +/// +/// Only is guaranteed. A serialization failure is detected while reading a row, +/// before there is an to inspect, so it may know nothing but the sequence and the +/// stored type alias — every other member is nullable for exactly that reason. Whatever IS known lets a +/// consumer correlate the failure with a row for the same +/// (projection, shard, sequence) if the event is later skipped. +/// +/// +public interface IEventFailureContext +{ + /// + /// How the daemon should classify a shard failure caused by this exception. + /// + ShardFailureCategory Category { get; } + + /// + /// Store-wide sequence number of the failing event. The one member every implementation can supply, + /// and the key a consumer joins on to find a matching . + /// + long Sequence { get; } + + /// + /// The event store's type alias for the failing event (e.g. trip_started), when known. + /// + string? EventTypeName { get; } + + /// + /// Unique id of the failing event, when the exception was raised late enough to have one. + /// + Guid? EventId { get; } + + /// + /// Stream id of the failing event for Guid-identified streams, when known. + /// + Guid? StreamId { get; } + + /// + /// Stream key of the failing event for string-identified streams, when known. + /// + string? StreamKey { get; } + + /// + /// Tenant the failing event belongs to, when known. Part of the dead-letter correlation key on + /// tenant-partitioned stores, where one shard accumulates failures per tenant. + /// + string? TenantId { get; } + + /// + /// Version of the failing event within its stream, when known. + /// + long? Version { get; } +} diff --git a/src/JasperFx.Events/Daemon/ISubscriptionAgent.cs b/src/JasperFx.Events/Daemon/ISubscriptionAgent.cs index a1068b4..cf56418 100644 --- a/src/JasperFx.Events/Daemon/ISubscriptionAgent.cs +++ b/src/JasperFx.Events/Daemon/ISubscriptionAgent.cs @@ -18,6 +18,22 @@ public interface ISubscriptionAgent : ISubscriptionController long HighWaterMark => 0; DateTimeOffset? PausedTime { get; } + + /// + /// jasperfx#565: WHY this agent was paused or stopped, if it was. alone told an + /// external supervisor (Wolverine's EventSubscriptionAgent, which wraps a shard as a + /// distributed agent) that a shard had paused but never what to do about it, so progress could + /// flatline with no actionable alert. Set alongside when a failure is reported, + /// and cleared when the agent starts or replays. + /// + /// + /// Defaulted to null so implementations that don't track failures — test doubles, wrappers that + /// delegate — are unaffected. A wrapper around a live inner agent should delegate this the same way + /// it delegates . + /// + /// + ShardFailure? Failure => null; + ISubscriptionMetrics Metrics { get; } void MarkHighWater(long sequence); diff --git a/src/JasperFx.Events/Daemon/ShardFailure.cs b/src/JasperFx.Events/Daemon/ShardFailure.cs new file mode 100644 index 0000000..5c1576a --- /dev/null +++ b/src/JasperFx.Events/Daemon/ShardFailure.cs @@ -0,0 +1,176 @@ +using JasperFx.Core.Reflection; + +namespace JasperFx.Events.Daemon; + +/// +/// jasperfx#565: WHY a projection/subscription shard was paused or stopped, in a form that survives +/// leaving the process. +/// +/// +/// Before this, an external supervisor — Wolverine's EventSubscriptionAgent wrapping a shard as a +/// distributed agent, or CritterWatch polling the store — could see and +/// nothing else. Progress silently flatlined and no alert could say what to do about it. The daemon has +/// always had the exception in hand ( +/// is the single funnel every failure path reaches); this is that knowledge, classified and made +/// portable. +/// +/// +/// +/// Deliberately a plain value rather than an : consumers serialize it, persist it +/// onto the store's extended progression row, and render it. still +/// carries the live exception for in-process observers. +/// +/// +public record ShardFailure +{ + /// + /// What kind of failure this was, and therefore what an operator should do about it. + /// + public required ShardFailureCategory Category { get; init; } + + /// + /// Type of the exception the daemon caught, as a code-readable full name. + /// + public required string ExceptionType { get; init; } + + /// + /// Type of the innermost exception, which for the wrapping cases (, + /// , an ) is the one that actually + /// names the fault — the same choice makes. Equal to + /// when nothing was wrapped. + /// + public required string RootExceptionType { get; init; } + + /// + /// of the caught exception. Short enough for an alert subject line. + /// + public required string Message { get; init; } + + /// + /// The full , inner exceptions and stack traces included. This is + /// what has always carried, kept intact so nothing an operator + /// used to be able to read is lost. + /// + public required string Detail { get; init; } + + /// + /// The single event that broke this shard, when the failure could be attributed to one — i.e. every + /// category except and + /// . Null otherwise. + /// + public EventFailureDetails? Event { get; init; } + + /// + /// When the failure was observed. + /// + public required DateTimeOffset OccurredAt { get; init; } + + /// + /// of a dead-letter row describing this same failing event, if the + /// caller has one. + /// + /// + /// Null on the daemon's pause path, and that is on purpose: a paused shard has NOT skipped the event, + /// so writing a dead letter there would inflate the dead-letter counts that stores report as their + /// "this projection is unhealthy" signal, and would rewrite a row on every restart attempt. When the + /// same event is later skipped ( and friends), the + /// dead letter it produces is correlatable through + /// — projection name, shard key, sequence and + /// tenant all line up. This slot exists for the paths that DO have a row in hand. + /// + /// + public Guid? DeadLetterEventId { get; init; } + + /// + /// Classify a caught exception. The single place any of this is decided, so the daemon, the stores and + /// an external supervisor never disagree about what a failure was. + /// + /// + /// The failing event is found by walking the whole exception graph — inner exceptions and + /// alike — for an + /// , because the per-event exceptions routinely arrive wrapped + /// ( around an , an + /// of several apply failures). The category comes from that context, + /// so a store's exception declares its own kind rather than the daemon sniffing type names. + /// + /// + public static ShardFailure For(Exception exception, DateTimeOffset occurredAt) + { + var context = findEventFailure(exception); + var category = context?.Category + ?? (hasProgressionOutOfOrder(exception) + ? ShardFailureCategory.ProgressionOutOfOrder + : ShardFailureCategory.Other); + + return new ShardFailure + { + Category = category, + ExceptionType = exception.GetType().FullNameInCode(), + RootExceptionType = rootOf(exception).GetType().FullNameInCode(), + Message = exception.Message, + Detail = exception.ToString(), + Event = context == null ? null : EventFailureDetails.From(context), + OccurredAt = occurredAt + }; + } + + private static IEventFailureContext? findEventFailure(Exception exception) + { + if (exception is IEventFailureContext context) return context; + + if (exception is AggregateException aggregate) + { + // Several apply failures in one batch is the common shape here. First one wins: the shard + // stops at the earliest failing event anyway, and the full text of all of them is in Detail. + foreach (var inner in aggregate.InnerExceptions.OrderBy(sequenceOf)) + { + var found = findEventFailure(inner); + if (found != null) return found; + } + + return null; + } + + return exception.InnerException == null ? null : findEventFailure(exception.InnerException); + } + + private static long sequenceOf(Exception exception) + => findEventFailure(exception)?.Sequence ?? long.MaxValue; + + private static bool hasProgressionOutOfOrder(Exception exception) + { + if (exception is ProgressionProgressOutOfOrderException) return true; + + if (exception is AggregateException aggregate) + { + return aggregate.InnerExceptions.Any(hasProgressionOutOfOrder); + } + + return exception.InnerException != null && hasProgressionOutOfOrder(exception.InnerException); + } + + private static Exception rootOf(Exception exception) + { + // An AggregateException's "root" is ambiguous; treat the first inner as the representative one, + // matching which failure findEventFailure would have reported. + while (true) + { + if (exception is AggregateException { InnerExceptions.Count: > 0 } aggregate) + { + exception = aggregate.InnerExceptions.OrderBy(sequenceOf).First(); + continue; + } + + if (exception.InnerException == null) return exception; + + exception = exception.InnerException; + } + } + + public override string ToString() + { + return Event == null + ? $"{Category}: {Message}" + : $"{Category} on {Event}: {Message}"; + } +} diff --git a/src/JasperFx.Events/Daemon/ShardFailureCategory.cs b/src/JasperFx.Events/Daemon/ShardFailureCategory.cs new file mode 100644 index 0000000..ceb8bf0 --- /dev/null +++ b/src/JasperFx.Events/Daemon/ShardFailureCategory.cs @@ -0,0 +1,50 @@ +namespace JasperFx.Events.Daemon; + +/// +/// jasperfx#565: what KIND of failure stopped or paused a projection/subscription shard. A supervisor +/// outside the daemon (Wolverine's assignment plane, CritterWatch) can only see +/// today, which says a shard is paused but never why — and the operator response is completely different +/// per category: a poison event needs a code fix or a skip, a serialization failure needs a serializer or +/// data fix, an unknown event type is usually a deployment/registration gap, and an out-of-order +/// progression means two processes are racing the same shard. +/// +public enum ShardFailureCategory +{ + /// + /// User projection/subscription code threw while applying an event — the classic "poison pill". + /// Carries the failing event (see ). Turning on + /// converts this into a dead letter instead + /// of a pause. + /// + ApplyEvent, + + /// + /// The event store could not deserialize or upcast a persisted event body. The store's own + /// exception (e.g. Marten's EventDeserializationFailureException) reports this category + /// through . Governed by + /// . + /// + EventSerialization, + + /// + /// An event's stored type alias resolves to no known .NET type in THIS deployment — usually a + /// missing registration or a rollback to a version that predates the event type, rather than + /// bad data. Kept separate from because the operator response + /// differs. Governed by . + /// + UnknownEventType, + + /// + /// The shard's progression row moved underneath it + /// (), which almost always means two + /// processes are running the same shard. Note that the daemon stops rather than pauses + /// on this one. + /// + ProgressionOutOfOrder, + + /// + /// Anything else: a database outage, a timeout, a bug in the daemon itself. No single event can + /// be blamed, so is null. + /// + Other +} diff --git a/src/JasperFx.Events/Daemon/ShardStateTracker.cs b/src/JasperFx.Events/Daemon/ShardStateTracker.cs index 1e52184..fb50d5b 100644 --- a/src/JasperFx.Events/Daemon/ShardStateTracker.cs +++ b/src/JasperFx.Events/Daemon/ShardStateTracker.cs @@ -1,4 +1,5 @@ using System.Collections.Immutable; +using System.Diagnostics.CodeAnalysis; using ImTools; using JasperFx.Blocks; using JasperFx.Core; @@ -144,6 +145,40 @@ public ValueTask MarkSkippingAsync(long lastKnownGoodHighWaterMark, long newHigh }); } + /// + /// jasperfx#565: the last state published for a single shard, or null if this tracker has never seen + /// it. The tracker has always kept this map to satisfy , + /// but it was private, so the only way to observe a shard was to subscribe BEFORE the interesting + /// transition happened, or to block in a wait. An external poller — a supervisor asking "is this + /// shard paused, and why?" on its own schedule — had no synchronous snapshot to read; this is it, + /// including on a paused or stopped shard. + /// + /// The raw , or . + public ShardState? CurrentState(string shardName) + => _states.TryFind(shardName, out var state) ? state : null; + + /// + /// for a strongly typed shard name. + /// + public ShardState? CurrentState(ShardName shardName) => CurrentState(shardName.Identity); + + /// + /// Try-get form of . + /// + public bool TryGetCurrentState(string shardName, [NotNullWhen(true)] out ShardState? state) + { + state = CurrentState(shardName); + return state != null; + } + + /// + /// Snapshot of the last state published for every shard this tracker has seen, including the + /// pseudo-shard. Point in time and safe to enumerate — the + /// underlying map is immutable, so a concurrent publication can't disturb the returned list. + /// + public IReadOnlyList CurrentStates() + => _states.Enumerate().Select(x => x.Value).ToList(); + /// /// Use to "wait" for an expected projection shard state /// diff --git a/src/JasperFx.Events/Daemon/SubscriptionAgent.cs b/src/JasperFx.Events/Daemon/SubscriptionAgent.cs index 38401c4..1512f0c 100644 --- a/src/JasperFx.Events/Daemon/SubscriptionAgent.cs +++ b/src/JasperFx.Events/Daemon/SubscriptionAgent.cs @@ -140,6 +140,14 @@ public async Task ReportCriticalFailureAsync(Exception ex) await _cancellation.CancelAsync().ConfigureAwait(false); await _execution.HardStopAsync().ConfigureAwait(false); + // jasperfx#565: every failure path in the daemon funnels through here, so this is the one + // place the reason gets classified. Published on the ShardState AND held on the agent, because + // the two consumers differ: the tracker feeds observers and the persisted extended progression + // row, while an external supervisor (Wolverine's EventSubscriptionAgent) polls the live agent. + // PauseReason keeps carrying the full exception text it always did. + var failure = ShardFailure.For(ex, _timeProvider.GetUtcNow()); + Failure = failure; + if (ex is ProgressionProgressOutOfOrderException) { PausedTime = null; @@ -149,7 +157,8 @@ await _tracker.PublishAsync(new ShardState(Name, LastCommitted) Action = ShardAction.Stopped, Exception = ex, AgentStatus = "Stopped", - PauseReason = ex.ToString(), + PauseReason = failure.Detail, + Failure = failure, LastHeartbeat = _timeProvider.GetUtcNow() }); } @@ -162,7 +171,8 @@ await _tracker.PublishAsync(new ShardState(Name, LastCommitted) Action = ShardAction.Paused, Exception = ex, AgentStatus = "Paused", - PauseReason = ex.ToString(), + PauseReason = failure.Detail, + Failure = failure, LastHeartbeat = _timeProvider.GetUtcNow() }); } @@ -239,6 +249,11 @@ public async Task StartAsync(SubscriptionExecutionRequest request) ErrorOptions = request.ErrorHandling; _runtime = request.Runtime; + // jasperfx#565: a fresh start supersedes whatever paused this agent last. Clearing it here (rather + // than leaving the last reason hanging around) is what keeps a supervisor from alerting on a + // failure the operator already recovered from. + Failure = null; + await _commandBlock.PostAsync(Command.Started(request.StartingHighWater ?? _tracker.HighWaterMark, request.Floor)); await _tracker.PublishAsync(new ShardState(Name, request.Floor) { @@ -259,6 +274,7 @@ public async Task ReplayAsync(SubscriptionExecutionRequest request, long highWat _execution.Mode = ShardExecutionMode.Rebuild; ErrorOptions = request.ErrorHandling; _runtime = request.Runtime; + Failure = null; // jasperfx#565: see StartAsync LastCommitted = request.Floor; // Force it to start here! _bufferedCeiling = request.Floor; // jasperfx#525 @@ -308,6 +324,13 @@ public Task RecordDeadLetterEventAsync(IEvent @event, Exception ex) public DateTimeOffset? PausedTime { get; private set; } + /// + /// jasperfx#565: the classified reason this agent last paused or stopped, or null while it is healthy. + /// Set in and cleared by a start or a replay, so a + /// supervisor polling it never reads a stale reason against a running agent. + /// + public ShardFailure? Failure { get; private set; } + public ISubscriptionMetrics Metrics { get; } public async ValueTask MarkSuccessAsync(long processedCeiling) diff --git a/src/JasperFx.Events/IEventDatabase.cs b/src/JasperFx.Events/IEventDatabase.cs index 33133d8..053aeeb 100644 --- a/src/JasperFx.Events/IEventDatabase.cs +++ b/src/JasperFx.Events/IEventDatabase.cs @@ -149,6 +149,14 @@ Task DeleteProjectionProgressByShardNameAsync(string shardIdentity, Cancellation /// Do NOT advance or regress last_seq_id-equivalent progression from this path. /// Progression is owned by the projection batch commit; this write updates only the extended /// telemetry columns, so it can never race a concurrent batch commit into losing progress. + /// jasperfx#565: persist when it is non-null, and CLEAR the + /// persisted failure when it is null on a state — a + /// recovered shard must not keep reporting the reason it paused an hour ago. The classified fields + /// worth their own columns are , + /// and + /// of , and the tenant; the rest of the reason text already rides + /// in the existing pause-reason column ( is exactly what + /// carries). /// /// /// The default implementation is a graceful no-op so existing stores compile and degrade @@ -156,7 +164,8 @@ Task DeleteProjectionProgressByShardNameAsync(string shardIdentity, Cancellation /// /// /// The published shard state carrying , - /// , and + /// , , + /// and /// for the shard named by /// . /// diff --git a/src/JasperFx.Events/Projections/ShardState.cs b/src/JasperFx.Events/Projections/ShardState.cs index 01ee771..2c67555 100644 --- a/src/JasperFx.Events/Projections/ShardState.cs +++ b/src/JasperFx.Events/Projections/ShardState.cs @@ -90,6 +90,20 @@ public ShardState(ShardName shardName, long sequence): this(shardName.Identity, /// public string? PauseReason { get; set; } + /// + /// jasperfx#565: the classified reason this shard was paused or stopped — category, the failing + /// event when one can be blamed, and the exception text — as a plain serializable value an external + /// supervisor can act on. still carries the live exception for in-process + /// observers; this is what survives a hop to Wolverine's assignment plane, a persisted extended + /// progression row, or a CritterWatch alert. Null on every state that isn't reporting a failure. + /// + /// + /// is kept in lockstep (it is ), so + /// consumers that only read the string are unaffected. + /// + /// + public ShardFailure? Failure { get; set; } + /// /// The node number that is currently running this shard ///