Additional information spit out into test failures w/ end to end test…

src/Persistence/Wolverine.Marten/TestingExtensions.cs

@@ -1,5 +1,11 @@
+using JasperFx.Core;
+using JasperFx.Core.Reflection;
+using JasperFx.Events.Projections;
 using Marten;
 using Marten.Events;
+using Marten.Events.Daemon.Coordination;
+using Microsoft.Extensions.DependencyInjection;
+using Wolverine.Runtime;
 using Wolverine.Tracking;
 
 namespace Wolverine.Marten;
@@ -46,16 +52,55 @@ public static TrackedSessionConfiguration PauseThenCatchUpOnMartenDaemonActivity
     {
         configuration.BeforeExecution(async (runtime, cancellation) =>
         {
+            var envelope = new Envelope
+            {
+                MessageType = "Pause:Marten:Daemons"
+            };
+
+            runtime.MessageTracking.ExecutionStarted(envelope);
+
             await runtime.Services.PauseAllDaemonsAsync();
+
+            runtime.MessageTracking.ExecutionFinished(envelope);
         });
 
         return configuration.AddStage(async (runtime, _, cancellation) =>
         {
-            var exceptions = await runtime.Services.ForceAllMartenDaemonActivityToCatchUpAsync(cancellation, mode);
-            foreach (var e in exceptions)
+            var envelope = new Envelope
+            {
+                MessageType = "CatchUp:Marten:DaemonActivity"
+            };
+
+            runtime.MessageTracking.ExecutionStarted(envelope);
+
+            // TODO -- be nice if this was in Marten itself
+            var coordinator = runtime.Services.GetRequiredService<IProjectionCoordinator>();
+            var daemons = await coordinator.AllDaemonsAsync().ConfigureAwait(false);
+            var subscriptions = new List<IDisposable>();
+            var observer = new TrackedSessionShardWatcher(runtime);
+            foreach (var daemon in daemons)
+            {
+                var subscription = daemon.Tracker.Subscribe(observer);
+                subscriptions.Add(subscription);
+            }
+
+            try
+            {
+                var exceptions = await runtime.Services.ForceAllMartenDaemonActivityToCatchUpAsync(cancellation, mode);
+                foreach (var exception in exceptions)
+                {
+                    runtime.MessageTracking.LogException(exception);
+                }
+            }
+            finally
             {
-                runtime.MessageTracking.LogException(e);
+                foreach (var subscription in subscriptions)
+                {
+                    subscription.SafeDispose();
+                }
             }
+
+            runtime.MessageTracking.ExecutionFinished(envelope);
         });
     }
 
@@ -73,16 +118,55 @@ public static TrackedSessionConfiguration PauseThenCatchUpOnMartenDaemonActivity
     {
         configuration.BeforeExecution(async (runtime, cancellation) =>
         {
+            var envelope = new Envelope
+            {
+                MessageType = "Pause:Marten:Daemons:" + typeof(T).NameInCode()
+            };
+
+            runtime.MessageTracking.ExecutionStarted(envelope);
+
             await runtime.Services.PauseAllDaemonsAsync<T>();
+
+            runtime.MessageTracking.ExecutionFinished(envelope);
         });
 
         return configuration.AddStage(async (runtime, _, cancellation) =>
         {
-            var exceptions = await runtime.Services.ForceAllMartenDaemonActivityToCatchUpAsync<T>(cancellation, mode);
-            foreach (var exception in exceptions)
+            var envelope = new Envelope
+            {
+                MessageType = "CatchUp:Marten:DaemonActivity:" + typeof(T).FullNameInCode()
+            };
+
+            runtime.MessageTracking.ExecutionStarted(envelope);
+
+            // TODO -- be nice if this was in Marten itself
+            var coordinator = runtime.Services.GetRequiredService<IProjectionCoordinator<T>>();
+            var daemons = await coordinator.AllDaemonsAsync().ConfigureAwait(false);
+            var subscriptions = new List<IDisposable>();
+            var observer = new TrackedSessionShardWatcher(runtime);
+            foreach (var daemon in daemons)
+            {
+                var subscription = daemon.Tracker.Subscribe(observer);
+                subscriptions.Add(subscription);
+            }
+
+            try
+            {
+                var exceptions = await runtime.Services.ForceAllMartenDaemonActivityToCatchUpAsync<T>(cancellation, mode);
+                foreach (var exception in exceptions)
+                {
+                    runtime.MessageTracking.LogException(exception);
+                }
+            }
+            finally
             {
-                runtime.MessageTracking.LogException(exception);
+                foreach (var subscription in subscriptions)
+                {
+                    subscription.SafeDispose();
+                }
             }
+
+            runtime.MessageTracking.ExecutionFinished(envelope);
         });
     }
 
@@ -132,4 +216,29 @@ public static TrackedSessionConfiguration WaitForNonStaleDaemonDataAfterExecutio
             }
         });
     }
+}
+
+internal class TrackedSessionShardWatcher : IObserver<ShardState>
+{
+    private readonly IWolverineRuntime _runtime;
+
+    public TrackedSessionShardWatcher(IWolverineRuntime runtime)
+    {
+        _runtime = runtime;
+    }
+
+    public void OnCompleted()
+    {
+
+    }
+
+    public void OnError(Exception error)
+    {
+
+    }
+
+    public void OnNext(ShardState value)
+    {
+        _runtime.MessageTracking.LogStatus(value.ToString());
+    }
 }

src/Wolverine/Logging/IMessageLogger.cs

@@ -7,6 +7,13 @@ namespace Wolverine.Logging;
 /// </summary>
 public interface IMessageTracker
 {
+    /// <summary>
+    /// Strictly for automated testing support. Simply track a message that will be displayed
+    /// in the execution order in any test failures from timeouts with tracked sessions
+    /// </summary>
+    /// <param name="message"></param>
+    void LogStatus(string message);
+
     /// <summary>
     ///     Catch all hook for any exceptions encountered by the messaging
     /// </summary>

src/Wolverine/Runtime/WolverineRuntime.DirectMetrics.cs

@@ -29,7 +29,12 @@ public void LogException(Exception ex, object? correlationId = null, string mess
         {
             _runtime.LogException(ex, correlationId, message);
         }
-
+
+        public void LogStatus(string message)
+        {
+            _runtime.ActiveSession?.LogStatus(message);
+        }
+
         public ILogger Logger { get; }
 
         public void Sent(Envelope envelope)

src/Wolverine/Runtime/WolverineRuntime.HybridMetricsPublishingMessageTracker.cs

@@ -32,6 +32,11 @@ public void Received(Envelope envelope)
         {
             _runtime.Received(envelope);
         }
+
+        public void LogStatus(string message)
+        {
+            _runtime.ActiveSession?.LogStatus(message);
+        }
 
         public void ExecutionStarted(Envelope envelope)
         {

src/Wolverine/Runtime/WolverineRuntime.Tracking.cs

@@ -161,4 +161,9 @@ public void LogException(Exception ex, object? correlationId = null,
         ActiveSession?.LogException(ex, _serviceName);
         Logger.LogError(ex, message);
     }
+
+    public void LogStatus(string message)
+    {
+        ActiveSession?.LogStatus(message);
+    }
 }

src/Wolverine/Tracking/EnvelopeRecord.cs

@@ -6,15 +6,15 @@ namespace Wolverine.Tracking;
 
 public class EnvelopeRecord
 {
-    public EnvelopeRecord(MessageEventType eventType, Envelope envelope, long sessionTime, Exception? exception)
+    public EnvelopeRecord(MessageEventType eventType, Envelope? envelope, long sessionTime, Exception? exception)
     {
         Envelope = envelope;
         SessionTime = sessionTime;
         Exception = exception;
         MessageEventType = eventType;
-        AttemptNumber = envelope.Attempts;
+        AttemptNumber = envelope?.Attempts ?? 0;
 
-        WasScheduled = envelope.IsScheduledForLater(DateTimeOffset.UtcNow);
+        WasScheduled = envelope?.IsScheduledForLater(DateTimeOffset.UtcNow) ?? false;
 
         var activity = Activity.Current;
         if (activity != null)
@@ -24,10 +24,10 @@ public EnvelopeRecord(MessageEventType eventType, Envelope envelope, long sessio
             ActivityId = activity.Id;
         }
     }
-
+    
     public bool WasScheduled { get; set; }
 
-    public object? Message => Envelope.Message;
+    public object? Message => Envelope?.Message;
 
     /// <summary>
     ///     If available, the open telemetry activity id when
@@ -37,7 +37,7 @@ public EnvelopeRecord(MessageEventType eventType, Envelope envelope, long sessio
     public string? ParentId { get; init; }
     public string? RootId { get; init; }
 
-    public Envelope Envelope { get; private set; }
+    public Envelope? Envelope { get; private set; }
 
     /// <summary>
     ///     A timestamp of the milliseconds since the tracked session was started before this event

src/Wolverine/Tracking/MessageEventType.cs

@@ -14,6 +14,7 @@ public enum MessageEventType
     MovedToErrorQueue,
     Requeued,
     Scheduled,
-    Discarded
+    Discarded,
+    Status
 }
 #endregion

src/Wolverine/Tracking/TrackedSession.cs

@@ -17,6 +17,7 @@ internal partial class TrackedSession : ITrackedSession
     private readonly IList<ITrackedCondition> _conditions = new List<ITrackedCondition>();
 
     private Cache<Guid, EnvelopeHistory> _envelopes = new(id => new EnvelopeHistory(id));
+    private readonly List<EnvelopeRecord> _statuses = new();
 
     private readonly IList<Exception> _exceptions = new List<Exception>();
 
@@ -142,13 +143,14 @@ public EnvelopeRecord[] FindEnvelopesWithMessageType<T>()
 
     public EnvelopeRecord[] AllRecordsInOrder()
     {
-        return _envelopes.SelectMany(x => x.Records).OrderBy(x => x.SessionTime).ToArray();
+        return _envelopes.SelectMany(x => x.Records).Concat(_statuses).OrderBy(x => x.SessionTime).ToArray();
     }
 
     public EnvelopeRecord[] AllRecordsInOrder(MessageEventType eventType)
     {
         return _envelopes
             .SelectMany(x => x.Records)
+            .Concat(_statuses)
             .Where(x => x.MessageEventType == eventType)
             .OrderBy(x => x.SessionTime)
             .ToArray();
@@ -483,6 +485,12 @@ public void IgnoreMessageTypes(Func<Type, bool> filter)
     {
         _ignoreMessageRules.Add(filter);
     }
+
+    public void LogStatus(string message)
+    {
+        var record = new EnvelopeRecord(MessageEventType.Status, null, _stopwatch.ElapsedMilliseconds, null);
+        _statuses.Add(record);
+    }
 }
 
 internal class HostWrapper : IHost