Joseph Doherty
56c99c92c3
F1: deploy/wonder-app-vd03/appsettings.Site.json (outside git, WP1.2's StartupValidator gate applies live on next install/upgrade) was missing the now-required AuditLog:SiteWriter:DatabasePath, added pointing at E:\ApiInstall\ScadaBridge\site\data\auditlog.db alongside the file's existing SiteEventLog/LocalDb paths; scanned deploy/ for other Site-role appsettings with the same gap (none) and confirmed wonder does not pin LocalDb:Replication:MaxBatchSize (F2 doesn't apply there). F2: re-pin an explicit LocalDb:Replication:MaxBatchSize=64 on docker/site-a node-a and node-b. MaxBatchBytes (2 MB default) only bounds the wire message via the per-message split in SyncSession.PumpLoopAsync; MaxBatchSize separately bounds the DB read page in OplogStore.ReadBatchAboveAsync/SnapshotStreamer, which materializes the whole page into memory before that split runs. Left at the 500 default, a reconnect drain of worst-case config_json rows could transiently allocate ~35 MB per read even though every wire message stayed within budget. Updated the CLAUDE.md LocalDb bullet to stop implying the row cap is fully redundant with the byte budget (topology-guide.md has no matching claim). F3: StoreAndForwardService's observer-queue onDropped callback logged a Warning per dropped item, flooding logs at sweep rate for a stuck observer with a large queue. LogObserverQueueDrop now logs once immediately on the first drop of an episode, then throttles to at most one rollup Warning per minute while drops continue, reporting the count dropped since the last log; the cumulative ObserverQueueDroppedCount counter is unaffected. Extended StoreAndForwardServiceTests with ObserverQueue_ManyDropsInOneEpisode_LogsExactlyOneWarning, which floods the bounded queue and pins exactly one drop-related Warning log for the episode via a small CapturingLogger test double. dotnet build ZB.MOM.WW.ScadaBridge.slnx: 0 warnings, 0 errors. dotnet test StoreAndForward.Tests: 134/134 passed. dotnet test Host.Tests: 490/490 passed.
1075 lines
45 KiB
C#
1075 lines
45 KiB
C#
using Microsoft.Extensions.Logging;
|
|
using Microsoft.Extensions.Logging.Abstractions;
|
|
using ZB.MOM.WW.ScadaBridge.Commons.Interfaces.Services;
|
|
using ZB.MOM.WW.ScadaBridge.Commons.Types;
|
|
using ZB.MOM.WW.ScadaBridge.Commons.Types.Enums;
|
|
using ZB.MOM.WW.ScadaBridge.TestSupport;
|
|
|
|
namespace ZB.MOM.WW.ScadaBridge.StoreAndForward.Tests;
|
|
|
|
/// <summary>
|
|
/// WP-10/12/13/14: Tests for the StoreAndForwardService retry engine and management.
|
|
/// </summary>
|
|
public class StoreAndForwardServiceTests : IAsyncLifetime, IDisposable
|
|
{
|
|
private readonly TestLocalDb _localDb;
|
|
private readonly StoreAndForwardStorage _storage;
|
|
private readonly StoreAndForwardService _service;
|
|
private readonly StoreAndForwardOptions _options;
|
|
private readonly List<TestLocalDb> _extraLocalDbs = new();
|
|
|
|
public StoreAndForwardServiceTests()
|
|
{
|
|
_localDb = TestLocalDb.CreateTemp("SvcTests");
|
|
|
|
_storage = new StoreAndForwardStorage(_localDb.Db, NullLogger<StoreAndForwardStorage>.Instance);
|
|
|
|
_options = new StoreAndForwardOptions
|
|
{
|
|
DefaultRetryInterval = TimeSpan.Zero,
|
|
DefaultMaxRetries = 3,
|
|
RetryTimerInterval = TimeSpan.FromMinutes(10)
|
|
};
|
|
|
|
_service = new StoreAndForwardService(
|
|
_storage, _options, NullLogger<StoreAndForwardService>.Instance);
|
|
}
|
|
|
|
public async Task InitializeAsync() => await _storage.InitializeAsync();
|
|
|
|
public Task DisposeAsync() => Task.CompletedTask;
|
|
|
|
public void Dispose()
|
|
{
|
|
DisposeLocalDb(_localDb);
|
|
foreach (var db in _extraLocalDbs) DisposeLocalDb(db);
|
|
}
|
|
|
|
/// <summary>Disposes a local database, then removes its file and WAL sidecars.</summary>
|
|
private static void DisposeLocalDb(TestLocalDb localDb)
|
|
{
|
|
var path = localDb.Path;
|
|
localDb.Dispose();
|
|
TestLocalDb.DeleteFiles(path);
|
|
}
|
|
|
|
/// <summary>
|
|
/// Builds a fresh service over its own local database so a test can call
|
|
/// StartAsync without racing the shared <c>_service</c>'s timer. The database
|
|
/// is tracked for disposal.
|
|
/// </summary>
|
|
private StoreAndForwardService CreateService(TimeSpan? retryTimerInterval = null)
|
|
{
|
|
var localDb = TestLocalDb.CreateTemp("DeferTests");
|
|
_extraLocalDbs.Add(localDb);
|
|
|
|
var storage = new StoreAndForwardStorage(localDb.Db, NullLogger<StoreAndForwardStorage>.Instance);
|
|
storage.InitializeAsync().GetAwaiter().GetResult();
|
|
|
|
var options = new StoreAndForwardOptions
|
|
{
|
|
DefaultRetryInterval = TimeSpan.Zero,
|
|
DefaultMaxRetries = 3,
|
|
RetryTimerInterval = retryTimerInterval ?? TimeSpan.FromMinutes(10),
|
|
};
|
|
return new StoreAndForwardService(storage, options, NullLogger<StoreAndForwardService>.Instance);
|
|
}
|
|
|
|
// ── WP-10: Immediate delivery ──
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_ImmediateDeliverySuccess_ReturnsAcceptedNotBuffered()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => Task.FromResult(true));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api.example.com",
|
|
"""{"method":"Test"}""", "Pump1");
|
|
|
|
Assert.True(result.Accepted);
|
|
Assert.False(result.WasBuffered);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_PermanentFailure_ReturnsNotAccepted()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => Task.FromResult(false));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api.example.com",
|
|
"""{"method":"Test"}""");
|
|
|
|
Assert.False(result.Accepted);
|
|
Assert.False(result.WasBuffered);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_TransientFailure_BuffersForRetry()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("Connection refused"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api.example.com",
|
|
"""{"method":"Test"}""", "Pump1");
|
|
|
|
Assert.True(result.Accepted);
|
|
Assert.True(result.WasBuffered);
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.NotNull(msg);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Pending, msg!.Status);
|
|
// StoreAndForward-003: RetryCount counts sweep retries only; the immediate
|
|
// attempt is attempt 0, so a freshly buffered message has RetryCount 0.
|
|
Assert.Equal(0, msg.RetryCount);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_NoHandler_BuffersForLater()
|
|
{
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.Notification, "alerts@company.com",
|
|
"""{"subject":"Alert"}""");
|
|
|
|
Assert.True(result.Accepted);
|
|
Assert.True(result.WasBuffered);
|
|
}
|
|
|
|
// ── WP-10: Retry engine ──
|
|
|
|
[Fact]
|
|
public async Task RetryPendingMessagesAsync_SuccessfulRetry_RemovesMessage()
|
|
{
|
|
int callCount = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ =>
|
|
{
|
|
callCount++;
|
|
if (callCount == 1) throw new HttpRequestException("fail");
|
|
return Task.FromResult(true);
|
|
});
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""");
|
|
Assert.True(result.WasBuffered);
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Null(msg);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetryPendingMessagesAsync_MaxRetriesReached_ParksMessage()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("always fails"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
maxRetries: 2);
|
|
|
|
// StoreAndForward-003: MaxRetries bounds sweep retries (not the immediate
|
|
// attempt), so a message with MaxRetries=2 needs two retry sweeps to park.
|
|
await _service.RetryPendingMessagesAsync();
|
|
var afterFirst = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Pending, afterFirst!.Status);
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.NotNull(msg);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Parked, msg!.Status);
|
|
}
|
|
|
|
// ── StoreAndForward-003: retry-count accounting ──
|
|
|
|
[Fact]
|
|
public async Task RetryPendingMessagesAsync_MaxRetriesOne_PerformsExactlyOneRetryBeforeParking()
|
|
{
|
|
// The immediate attempt is attempt 0; MaxRetries=1 must allow exactly one
|
|
// retry sweep before parking. The pre-fix off-by-one parked with zero retries.
|
|
var attempts = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => { Interlocked.Increment(ref attempts); throw new HttpRequestException("always fails"); });
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
maxRetries: 1);
|
|
|
|
// After the immediate failed attempt the message is buffered, not parked.
|
|
var buffered = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Pending, buffered!.Status);
|
|
Assert.Equal(1, attempts); // only the immediate attempt so far
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Parked, msg!.Status);
|
|
Assert.Equal(2, attempts); // immediate attempt + exactly one retry
|
|
Assert.Equal(1, msg.RetryCount); // one sweep retry recorded
|
|
}
|
|
|
|
// ── StoreAndForward-005: sweep-vs-management race hardening ──
|
|
|
|
[Fact]
|
|
public async Task RetryMessageAsync_StatusChangedDuringDelivery_SweepParkWriteIsSkipped()
|
|
{
|
|
// StoreAndForward-005: the retry sweep's state-changing writes must be
|
|
// conditional on the status it observed, so a concurrent operator action that
|
|
// moved the row out of Pending (e.g. between the sweep's snapshot load and its
|
|
// park write) is not silently overwritten by the sweep's stale view.
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
attemptImmediateDelivery: false, maxRetries: 1);
|
|
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
async msg =>
|
|
{
|
|
// Simulate an operator action winning the race: the row leaves Pending
|
|
// (here: parked) while the sweep is still mid-delivery. The sweep would
|
|
// otherwise unconditionally re-write this row from its stale snapshot.
|
|
var parkedOutFromUnderTheSweep = new StoreAndForwardMessage
|
|
{
|
|
Id = msg.Id, Category = msg.Category, Target = msg.Target,
|
|
PayloadJson = msg.PayloadJson, RetryCount = 7,
|
|
MaxRetries = msg.MaxRetries, RetryIntervalMs = msg.RetryIntervalMs,
|
|
CreatedAt = msg.CreatedAt, LastAttemptAt = DateTimeOffset.UtcNow,
|
|
Status = StoreAndForwardMessageStatus.Parked,
|
|
LastError = "operator/other writer"
|
|
};
|
|
await _storage.UpdateMessageAsync(parkedOutFromUnderTheSweep);
|
|
throw new HttpRequestException("transient — sweep will try to park");
|
|
});
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
// The sweep observed Pending; the row is now Parked with the other writer's
|
|
// RetryCount (7), not the sweep's (1). The sweep's conditional write was skipped.
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.NotNull(msg);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Parked, msg!.Status);
|
|
Assert.Equal(7, msg.RetryCount);
|
|
Assert.Equal("operator/other writer", msg.LastError);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetryPendingMessagesAsync_PermanentFailureOnRetry_ParksMessage()
|
|
{
|
|
int callCount = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ =>
|
|
{
|
|
callCount++;
|
|
if (callCount == 1) throw new HttpRequestException("transient");
|
|
return Task.FromResult(false);
|
|
});
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""");
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.NotNull(msg);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Parked, msg!.Status);
|
|
}
|
|
|
|
// ── WP-12: Parked message management ──
|
|
|
|
[Fact]
|
|
public async Task RetryParkedMessageAsync_MovesBackToQueue()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
maxRetries: 1);
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Parked, msg!.Status);
|
|
|
|
var retried = await _service.RetryParkedMessageAsync(result.MessageId);
|
|
Assert.True(retried);
|
|
|
|
msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Pending, msg!.Status);
|
|
Assert.Equal(0, msg.RetryCount);
|
|
}
|
|
|
|
/// <summary>
|
|
/// StoreAndForward-017: the Retry activity-log entry must carry the parked
|
|
/// message's true category, not a hard-coded ExternalSystem.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task RetryParkedMessageAsync_ActivityUsesMessageRealCategory()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.Notification,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.Notification, "ops-list", """{}""",
|
|
maxRetries: 1);
|
|
await _service.RetryPendingMessagesAsync(); // -> parked
|
|
|
|
var categories = new List<StoreAndForwardCategory>();
|
|
_service.OnActivity += (action, category, _) =>
|
|
{
|
|
if (action == "Retry") categories.Add(category);
|
|
};
|
|
|
|
var retried = await _service.RetryParkedMessageAsync(result.MessageId);
|
|
Assert.True(retried);
|
|
|
|
Assert.Equal(new[] { StoreAndForwardCategory.Notification }, categories);
|
|
}
|
|
|
|
/// <summary>
|
|
/// StoreAndForward-017: the Discard activity-log entry must carry the parked
|
|
/// message's true category, not a hard-coded ExternalSystem.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task DiscardParkedMessageAsync_ActivityUsesMessageRealCategory()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.CachedDbWrite,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.CachedDbWrite, "site-db", """{}""",
|
|
maxRetries: 1);
|
|
await _service.RetryPendingMessagesAsync(); // -> parked
|
|
|
|
var categories = new List<StoreAndForwardCategory>();
|
|
_service.OnActivity += (action, category, _) =>
|
|
{
|
|
if (action == "Discard") categories.Add(category);
|
|
};
|
|
|
|
var discarded = await _service.DiscardParkedMessageAsync(result.MessageId);
|
|
Assert.True(discarded);
|
|
|
|
Assert.Equal(new[] { StoreAndForwardCategory.CachedDbWrite }, categories);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task DiscardParkedMessageAsync_PermanentlyRemoves()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
maxRetries: 1);
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var discarded = await _service.DiscardParkedMessageAsync(result.MessageId);
|
|
Assert.True(discarded);
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Null(msg);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task GetParkedMessagesAsync_ReturnsPaginatedResults()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
for (int i = 0; i < 3; i++)
|
|
{
|
|
await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, $"api{i}", """{}""",
|
|
maxRetries: 1);
|
|
}
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var (messages, total) = await _service.GetParkedMessagesAsync(
|
|
StoreAndForwardCategory.ExternalSystem, 1, 2);
|
|
|
|
Assert.Equal(2, messages.Count);
|
|
Assert.True(total >= 3);
|
|
}
|
|
|
|
// ── WP-13: Messages survive instance deletion ──
|
|
|
|
[Fact]
|
|
public async Task MessagesForInstance_SurviveAfterDeletion()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""", "Pump1");
|
|
await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api2", """{}""", "Pump1");
|
|
|
|
var count = await _service.GetMessageCountForInstanceAsync("Pump1");
|
|
Assert.Equal(2, count);
|
|
}
|
|
|
|
// ── WP-14: Health metrics ──
|
|
|
|
[Fact]
|
|
public async Task GetBufferDepthAsync_ReturnsCorrectDepth()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.Notification,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "api1", """{}""");
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "api2", """{}""");
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.Notification, "email", """{}""");
|
|
|
|
var depth = await _service.GetBufferDepthAsync();
|
|
Assert.True(depth.GetValueOrDefault(StoreAndForwardCategory.ExternalSystem) >= 2);
|
|
Assert.True(depth.GetValueOrDefault(StoreAndForwardCategory.Notification) >= 1);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task OnActivity_RaisedOnEnqueue()
|
|
{
|
|
var activities = new List<string>();
|
|
_service.OnActivity += (action, _, _) => activities.Add(action);
|
|
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => Task.FromResult(true));
|
|
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "api", """{}""");
|
|
|
|
Assert.Contains("Delivered", activities);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task OnActivity_RaisedOnBuffer()
|
|
{
|
|
var activities = new List<string>();
|
|
_service.OnActivity += (action, _, _) => activities.Add(action);
|
|
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "api", """{}""");
|
|
|
|
Assert.Contains("Queued", activities);
|
|
}
|
|
|
|
// ── StoreAndForward-009: faulting activity subscriber must not corrupt delivery ──
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_ImmediateDeliverySuccess_FaultingActivitySubscriber_StillReportsDelivered()
|
|
{
|
|
// StoreAndForward-009: a throwing OnActivity subscriber (e.g. the site event
|
|
// log) must not be misclassified as a transient delivery failure. Pre-fix the
|
|
// subscriber's exception escaped RaiseActivity, was caught by EnqueueAsync's
|
|
// transient-failure handler, and a successfully delivered message was buffered.
|
|
_service.OnActivity += (_, _, _) => throw new InvalidOperationException("logging blew up");
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => Task.FromResult(true));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""");
|
|
|
|
Assert.True(result.Accepted);
|
|
Assert.False(result.WasBuffered); // delivered, NOT buffered
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Null(msg); // nothing left in the buffer
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetryMessageAsync_FaultingActivitySubscriber_DoesNotIncrementRetryCount()
|
|
{
|
|
// StoreAndForward-009: a throwing subscriber raised after a successful retry
|
|
// delivery must not be caught by the retry-failure handler and counted as a
|
|
// transient failure.
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
attemptImmediateDelivery: false, maxRetries: 5);
|
|
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => Task.FromResult(true));
|
|
_service.OnActivity += (_, _, _) => throw new InvalidOperationException("logging blew up");
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
// The retry succeeded; the message must be gone, not re-buffered with a bumped count.
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Null(msg);
|
|
}
|
|
|
|
// ── WP-10: Per-source-entity retry settings ──
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_CustomRetrySettings_Respected()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("fail"));
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
maxRetries: 100,
|
|
retryInterval: TimeSpan.FromSeconds(60));
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.Equal(100, msg!.MaxRetries);
|
|
Assert.Equal(60000, msg.RetryIntervalMs);
|
|
}
|
|
|
|
// ── attemptImmediateDelivery: false — caller already attempted delivery ──
|
|
|
|
[Fact]
|
|
public async Task EnqueueAsync_AttemptImmediateDeliveryFalse_BuffersWithoutInvokingHandler()
|
|
{
|
|
// A caller that has already made its own delivery attempt passes
|
|
// attemptImmediateDelivery: false so the request is not dispatched twice.
|
|
var handlerCalls = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => { Interlocked.Increment(ref handlerCalls); return Task.FromResult(true); });
|
|
|
|
var result = await _service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
attemptImmediateDelivery: false);
|
|
|
|
Assert.Equal(0, handlerCalls); // handler NOT invoked at enqueue time
|
|
Assert.True(result.WasBuffered);
|
|
|
|
var msg = await _storage.GetMessageByIdAsync(result.MessageId);
|
|
Assert.NotNull(msg);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Pending, msg!.Status);
|
|
// StoreAndForward-003: the caller's own attempt is attempt 0; RetryCount
|
|
// counts only sweep retries, so a freshly buffered message has RetryCount 0.
|
|
Assert.Equal(0, msg.RetryCount);
|
|
}
|
|
|
|
// ─── StoreAndForward-024: StopAsync waits for the in-flight sweep ───
|
|
|
|
/// <summary>
|
|
/// StoreAndForward-024: <see cref="StoreAndForwardService.StopAsync"/> must
|
|
/// not return until any in-flight retry sweep has completed (or the bounded
|
|
/// shutdown timeout fires). Pre-fix it disposed the timer and returned
|
|
/// immediately, leaving a mid-flight sweep touching disposed dependencies.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task StopAsync_AwaitsInFlightRetrySweep_BeforeReturning()
|
|
{
|
|
// Build a service whose timer fires almost immediately, with a handler
|
|
// that pauses in the middle of delivery so we can observe StopAsync's
|
|
// wait behaviour.
|
|
var localDb = TestLocalDb.CreateTemp("StopWait");
|
|
_extraLocalDbs.Add(localDb);
|
|
|
|
var storage = new StoreAndForwardStorage(localDb.Db, NullLogger<StoreAndForwardStorage>.Instance);
|
|
await storage.InitializeAsync();
|
|
|
|
var options = new StoreAndForwardOptions
|
|
{
|
|
DefaultRetryInterval = TimeSpan.Zero,
|
|
DefaultMaxRetries = 3,
|
|
// Fire almost immediately so the sweep is in-flight by the time we call StopAsync.
|
|
RetryTimerInterval = TimeSpan.FromMilliseconds(20),
|
|
};
|
|
var service = new StoreAndForwardService(
|
|
storage, options, NullLogger<StoreAndForwardService>.Instance);
|
|
|
|
// Pre-seed a buffered message so the sweep has work to do, and a
|
|
// handler that blocks until we release it.
|
|
var handlerEntered = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
|
|
var releaseHandler = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
|
|
var handlerCompleted = false;
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem, async _ =>
|
|
{
|
|
handlerEntered.TrySetResult();
|
|
await releaseHandler.Task;
|
|
handlerCompleted = true;
|
|
return true;
|
|
});
|
|
|
|
var seed = await service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, "api", """{}""",
|
|
attemptImmediateDelivery: false);
|
|
Assert.True(seed.WasBuffered);
|
|
|
|
await service.StartAsync();
|
|
// Wait until the timer-driven sweep has called into the handler.
|
|
var entered = await Task.WhenAny(handlerEntered.Task, Task.Delay(TimeSpan.FromSeconds(2)));
|
|
Assert.Same(handlerEntered.Task, entered);
|
|
Assert.False(handlerCompleted, "Handler should still be paused inside the sweep.");
|
|
|
|
// Kick StopAsync — it must NOT return until the sweep finishes. Run the
|
|
// release on a background task so we can prove StopAsync is awaiting.
|
|
var stopTask = service.StopAsync();
|
|
Assert.False(stopTask.IsCompleted,
|
|
"StopAsync returned before the in-flight sweep was given a chance to finish.");
|
|
|
|
// Release the handler — StopAsync should now complete shortly.
|
|
releaseHandler.SetResult();
|
|
await stopTask.WaitAsync(TimeSpan.FromSeconds(5));
|
|
Assert.True(handlerCompleted,
|
|
"Sweep handler must have finished before StopAsync returned.");
|
|
}
|
|
|
|
// ── Task 3 (arch review 02, Stability #2): active-node delivery gate ──
|
|
// The standby site node applies replicated buffer operations but must never
|
|
// deliver; the sweep runs only when the gate reports the node is active.
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_SkipsDelivery_WhenDeliveryGateReportsStandby()
|
|
{
|
|
var delivered = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => { delivered++; return Task.FromResult(true); });
|
|
_service.SetDeliveryGate(() => false); // standby
|
|
|
|
var result = await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "target-x", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
Assert.Equal(0, delivered);
|
|
var row = await _service.GetMessageByIdAsync(result.MessageId);
|
|
Assert.NotNull(row);
|
|
Assert.Equal(StoreAndForwardMessageStatus.Pending, row!.Status); // row untouched
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_ResumesDelivery_WhenGateFlipsActive()
|
|
{
|
|
var delivered = 0;
|
|
var active = false;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => { delivered++; return Task.FromResult(true); });
|
|
_service.SetDeliveryGate(() => active);
|
|
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "target-x", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
Assert.Equal(0, delivered);
|
|
|
|
active = true; // failover: this node became active
|
|
await _service.RetryPendingMessagesAsync();
|
|
Assert.Equal(1, delivered);
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_TreatsThrowingGateAsStandby()
|
|
{
|
|
var delivered = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => { delivered++; return Task.FromResult(true); });
|
|
_service.SetDeliveryGate(() => throw new InvalidOperationException("cluster not ready"));
|
|
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "t", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
await _service.RetryPendingMessagesAsync(); // must not throw
|
|
Assert.Equal(0, delivered);
|
|
}
|
|
|
|
// ── Task 8 (arch review 02, Performance): per-target short-circuit ──
|
|
// After the first transient failure to a (category, target) the remaining
|
|
// messages for that pair are skipped this sweep — N dead-target messages
|
|
// cost one timeout, not N. Skipped rows keep their RetryCount.
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_ShortCircuitsTarget_AfterFirstTransientFailure()
|
|
{
|
|
var attemptsByTarget = new Dictionary<string, int>();
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem, msg =>
|
|
{
|
|
attemptsByTarget[msg.Target] = attemptsByTarget.GetValueOrDefault(msg.Target) + 1;
|
|
if (msg.Target == "dead-target") throw new TimeoutException("down");
|
|
return Task.FromResult(true);
|
|
});
|
|
|
|
for (var i = 0; i < 3; i++)
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "dead-target", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "healthy-target", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
Assert.Equal(1, attemptsByTarget["dead-target"]); // pre-fix: 3
|
|
Assert.Equal(1, attemptsByTarget["healthy-target"]); // healthy lane unaffected
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_SkippedMessages_DoNotAccrueRetryCount()
|
|
{
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new TimeoutException("down"));
|
|
var id1 = (await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "dead", "{}",
|
|
maxRetries: 5, attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero)).MessageId;
|
|
var id2 = (await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "dead", "{}",
|
|
maxRetries: 5, attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero)).MessageId;
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
var r1 = (await _service.GetMessageByIdAsync(id1))!.RetryCount;
|
|
var r2 = (await _service.GetMessageByIdAsync(id2))!.RetryCount;
|
|
// Exactly one was attempted (RetryCount 1); the other was skipped by the
|
|
// short-circuit, its RetryCount untouched (0). Order-independent so the
|
|
// assertion doesn't depend on created_at tie-breaking.
|
|
Assert.Equal(new[] { 0, 1 }, new[] { r1, r2 }.OrderBy(x => x).ToArray());
|
|
}
|
|
|
|
// ── Task 9 (arch review 02, Performance): parallel per-target lanes ──
|
|
// A slow/dead target no longer serializes the whole sweep; delivery within a
|
|
// single (category, target) lane stays sequential (per-target FIFO).
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_SlowTarget_DoesNotBlockOtherTargets()
|
|
{
|
|
var slowGate = new TaskCompletionSource();
|
|
var healthyDelivered = new TaskCompletionSource();
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem, async msg =>
|
|
{
|
|
if (msg.Target == "slow") { await slowGate.Task; return true; }
|
|
healthyDelivered.TrySetResult();
|
|
return true;
|
|
});
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "slow", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "healthy", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
|
|
var sweep = _service.RetryPendingMessagesAsync();
|
|
// Healthy lane completes while the slow lane is still blocked — pre-fix this
|
|
// times out because delivery is strictly serial across targets.
|
|
await healthyDelivered.Task.WaitAsync(TimeSpan.FromSeconds(5));
|
|
slowGate.SetResult();
|
|
await sweep;
|
|
}
|
|
|
|
[Fact]
|
|
public async Task RetrySweep_WithinTargetLane_StaysSequential()
|
|
{
|
|
var concurrent = 0;
|
|
var maxConcurrent = 0;
|
|
var delivered = 0;
|
|
_service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem, async _ =>
|
|
{
|
|
var c = Interlocked.Increment(ref concurrent);
|
|
InterlockedMax(ref maxConcurrent, c);
|
|
await Task.Delay(20);
|
|
Interlocked.Decrement(ref concurrent);
|
|
Interlocked.Increment(ref delivered);
|
|
return true;
|
|
});
|
|
for (var i = 0; i < 4; i++)
|
|
await _service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "same-target", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero, messageId: $"m{i}");
|
|
|
|
await _service.RetryPendingMessagesAsync();
|
|
|
|
Assert.Equal(4, delivered);
|
|
Assert.Equal(1, maxConcurrent); // one (category,target) lane: strictly sequential
|
|
}
|
|
|
|
private static void InterlockedMax(ref int target, int value)
|
|
{
|
|
int current;
|
|
do { current = Volatile.Read(ref target); if (value <= current) return; }
|
|
while (Interlocked.CompareExchange(ref target, value, current) != current);
|
|
}
|
|
|
|
// ── Task 12: deferToSweep enqueue mode ──
|
|
|
|
/// <summary>
|
|
/// <c>deferToSweep: true</c> must NOT invoke the delivery handler inline (the
|
|
/// caller is on a latency-sensitive thread), and the buffered row must be due on
|
|
/// the very next sweep — <c>LastAttemptAt</c> stays null so it is not held back by
|
|
/// RetryInterval.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task Enqueue_DeferToSweep_DoesNotInvokeHandlerInline_AndRowIsDueImmediately()
|
|
{
|
|
var service = CreateService();
|
|
var inlineInvoked = false;
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.Notification,
|
|
_ => { inlineInvoked = true; return Task.FromResult(true); });
|
|
|
|
var result = await service.EnqueueAsync(StoreAndForwardCategory.Notification, "ops", "{}",
|
|
deferToSweep: true, messageId: "n1");
|
|
|
|
Assert.False(inlineInvoked);
|
|
Assert.True(result.WasBuffered);
|
|
var row = await service.GetMessageByIdAsync("n1");
|
|
Assert.Null(row!.LastAttemptAt); // due on the very next sweep, not after RetryInterval
|
|
}
|
|
|
|
/// <summary>
|
|
/// After StartAsync, <c>deferToSweep</c> must kick an immediate background sweep so
|
|
/// healthy-path latency is milliseconds, not one timer interval — proven with a
|
|
/// timer set to an hour so only the kicked sweep can deliver.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task Enqueue_DeferToSweep_AfterStart_KicksAnImmediateSweep()
|
|
{
|
|
var service = CreateService(retryTimerInterval: TimeSpan.FromHours(1)); // timer will never fire in-test
|
|
var delivered = new TaskCompletionSource();
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.Notification,
|
|
_ => { delivered.TrySetResult(); return Task.FromResult(true); });
|
|
await service.StartAsync();
|
|
try
|
|
{
|
|
await service.EnqueueAsync(StoreAndForwardCategory.Notification, "ops", "{}", deferToSweep: true);
|
|
await delivered.Task.WaitAsync(TimeSpan.FromSeconds(5)); // pre-fix: times out
|
|
}
|
|
finally { await service.StopAsync(); }
|
|
}
|
|
|
|
// ── R2 T8: _sweepTask clobber (N3) ──
|
|
|
|
[Fact]
|
|
public async Task TriggerSweep_WhileSweepInFlight_DoesNotClobberTheDrainHandle()
|
|
{
|
|
var service = CreateService(retryTimerInterval: TimeSpan.FromHours(1));
|
|
var entered = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
|
|
var release = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem, async _ =>
|
|
{
|
|
entered.TrySetResult();
|
|
await release.Task;
|
|
return true;
|
|
});
|
|
await service.StartAsync();
|
|
try
|
|
{
|
|
await service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "t", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
|
|
service.TriggerSweep(); // real sweep, blocked in the handler
|
|
await entered.Task.WaitAsync(TimeSpan.FromSeconds(5));
|
|
service.TriggerSweep(); // redundant kick — pre-fix clobbers _sweepTask
|
|
|
|
var handle = service.CurrentSweepTaskForTest;
|
|
Assert.NotNull(handle);
|
|
Assert.False(handle!.IsCompleted); // pre-fix: true (a completed no-op replaced the real sweep)
|
|
}
|
|
finally
|
|
{
|
|
release.TrySetResult();
|
|
await service.StopAsync();
|
|
}
|
|
}
|
|
|
|
[Fact]
|
|
public async Task StopAsync_WaitsForTheRealInFlightSweep_EvenAfterARedundantTrigger()
|
|
{
|
|
var service = CreateService(retryTimerInterval: TimeSpan.FromHours(1));
|
|
var entered = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
|
|
var release = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously);
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem, async _ =>
|
|
{
|
|
entered.TrySetResult();
|
|
await release.Task;
|
|
return true;
|
|
});
|
|
await service.StartAsync();
|
|
await service.EnqueueAsync(StoreAndForwardCategory.ExternalSystem, "t", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero);
|
|
|
|
service.TriggerSweep();
|
|
await entered.Task.WaitAsync(TimeSpan.FromSeconds(5));
|
|
service.TriggerSweep(); // the clobbering kick
|
|
|
|
var stop = service.StopAsync();
|
|
await Task.Delay(300);
|
|
Assert.False(stop.IsCompleted); // pre-fix: StopAsync already returned (awaited the no-op)
|
|
|
|
release.TrySetResult();
|
|
await stop.WaitAsync(TimeSpan.FromSeconds(5)); // drains the real sweep promptly once released
|
|
}
|
|
|
|
// ── WP2.6c: bounded, DropOldest observer queue + drop counter ──
|
|
|
|
private sealed class BlockingObserver : ICachedCallLifecycleObserver
|
|
{
|
|
private readonly TaskCompletionSource _gate;
|
|
public BlockingObserver(TaskCompletionSource gate) => _gate = gate;
|
|
public async Task OnAttemptCompletedAsync(CachedCallAttemptContext context, CancellationToken ct = default)
|
|
=> await _gate.Task;
|
|
}
|
|
|
|
/// <summary>
|
|
/// WP2.6c: the cached-call audit-observer queue is bounded — once the single-reader
|
|
/// pump is stuck awaiting a slow/stuck observer, further posted notifications must
|
|
/// evict the oldest queued one (DropOldest) instead of growing without bound, and
|
|
/// every eviction must increment <see cref="StoreAndForwardService.ObserverQueueDroppedCount"/>.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task ObserverQueue_BoundedCapacity_DropsOldestAndCountsDrops()
|
|
{
|
|
var gate = new TaskCompletionSource();
|
|
var observer = new BlockingObserver(gate);
|
|
|
|
var localDb = TestLocalDb.CreateTemp("ObsQueueBound");
|
|
var storage = new StoreAndForwardStorage(localDb.Db, NullLogger<StoreAndForwardStorage>.Instance);
|
|
await storage.InitializeAsync();
|
|
var service = new StoreAndForwardService(
|
|
storage,
|
|
new StoreAndForwardOptions
|
|
{
|
|
DefaultRetryInterval = TimeSpan.Zero,
|
|
DefaultMaxRetries = 5,
|
|
RetryTimerInterval = TimeSpan.FromHours(1), // timer never fires in-test
|
|
ObserverQueueCapacity = 2,
|
|
},
|
|
NullLogger<StoreAndForwardService>.Instance,
|
|
cachedCallObserver: observer,
|
|
siteId: "site-77");
|
|
|
|
await service.StartAsync();
|
|
try
|
|
{
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("transient"));
|
|
|
|
// Enqueue more messages than the bounded capacity (2) — the pump dequeues
|
|
// the first notification and blocks on the observer gate, so every
|
|
// subsequent notification posted during this sweep queues (and, past
|
|
// capacity, evicts the oldest still-queued one) rather than being
|
|
// processed.
|
|
for (var i = 0; i < 6; i++)
|
|
{
|
|
await service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, $"t{i}", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero,
|
|
messageId: TrackedOperationId.New().ToString());
|
|
}
|
|
|
|
await service.RetryPendingMessagesAsync();
|
|
|
|
// Give the bounded channel a moment to have absorbed/evicted every post
|
|
// (the pump itself stays blocked on the gate throughout).
|
|
var deadline = DateTime.UtcNow + TimeSpan.FromSeconds(5);
|
|
while (DateTime.UtcNow < deadline && service.ObserverQueueDroppedCount == 0)
|
|
await Task.Delay(10);
|
|
|
|
Assert.True(service.ObserverQueueDroppedCount > 0,
|
|
"expected at least one notification to be dropped once the bounded queue filled");
|
|
}
|
|
finally
|
|
{
|
|
gate.TrySetResult();
|
|
await service.StopAsync();
|
|
var path = localDb.Path;
|
|
localDb.Dispose();
|
|
TestLocalDb.DeleteFiles(path);
|
|
}
|
|
}
|
|
|
|
/// <summary>
|
|
/// Captures every message logged through it, keyed by <see cref="LogLevel"/>. Minimal
|
|
/// test double — no scopes, no filtering — just enough to assert on log VOLUME.
|
|
/// </summary>
|
|
private sealed class CapturingLogger<T> : ILogger<T>
|
|
{
|
|
private readonly List<(LogLevel Level, string Message)> _entries = new();
|
|
private readonly object _gate = new();
|
|
|
|
public IReadOnlyList<(LogLevel Level, string Message)> Entries
|
|
{
|
|
get { lock (_gate) return _entries.ToList(); }
|
|
}
|
|
|
|
public IDisposable? BeginScope<TState>(TState state) where TState : notnull => null;
|
|
|
|
public bool IsEnabled(LogLevel logLevel) => true;
|
|
|
|
public void Log<TState>(
|
|
LogLevel logLevel, EventId eventId, TState state, Exception? exception,
|
|
Func<TState, Exception?, string> formatter)
|
|
{
|
|
var message = formatter(state, exception);
|
|
lock (_gate) _entries.Add((logLevel, message));
|
|
}
|
|
}
|
|
|
|
/// <summary>
|
|
/// arch-review adversarial finding F3: the observer-queue onDropped callback used to
|
|
/// log a Warning PER dropped item — a stuck observer with a large
|
|
/// <see cref="StoreAndForwardOptions.ObserverQueueCapacity"/> would flood the log at
|
|
/// sweep rate. Extends <see cref="ObserverQueue_BoundedCapacity_DropsOldestAndCountsDrops"/>
|
|
/// (same bounded-queue setup) to pin the fix: many drops in one episode still
|
|
/// increment <see cref="StoreAndForwardService.ObserverQueueDroppedCount"/> per drop, but
|
|
/// produce exactly ONE observer-queue-drop Warning log — the first-drop Warning — because
|
|
/// the episode never runs long enough to cross the periodic rollup interval.
|
|
/// </summary>
|
|
[Fact]
|
|
public async Task ObserverQueue_ManyDropsInOneEpisode_LogsExactlyOneWarning()
|
|
{
|
|
var gate = new TaskCompletionSource();
|
|
var observer = new BlockingObserver(gate);
|
|
var logger = new CapturingLogger<StoreAndForwardService>();
|
|
|
|
var localDb = TestLocalDb.CreateTemp("ObsQueueDropLogRollup");
|
|
var storage = new StoreAndForwardStorage(localDb.Db, NullLogger<StoreAndForwardStorage>.Instance);
|
|
await storage.InitializeAsync();
|
|
var service = new StoreAndForwardService(
|
|
storage,
|
|
new StoreAndForwardOptions
|
|
{
|
|
DefaultRetryInterval = TimeSpan.Zero,
|
|
DefaultMaxRetries = 5,
|
|
RetryTimerInterval = TimeSpan.FromHours(1), // timer never fires in-test
|
|
ObserverQueueCapacity = 2,
|
|
},
|
|
logger,
|
|
cachedCallObserver: observer,
|
|
siteId: "site-78");
|
|
|
|
await service.StartAsync();
|
|
try
|
|
{
|
|
service.RegisterDeliveryHandler(StoreAndForwardCategory.ExternalSystem,
|
|
_ => throw new HttpRequestException("transient"));
|
|
|
|
// Enqueue far more than the bounded capacity (2) so the queue overflows many
|
|
// times over in one sweep — same mechanism as the sibling test above, just a
|
|
// larger flood to make a per-item log flood obvious if the fix regresses.
|
|
for (var i = 0; i < 50; i++)
|
|
{
|
|
await service.EnqueueAsync(
|
|
StoreAndForwardCategory.ExternalSystem, $"t{i}", "{}",
|
|
attemptImmediateDelivery: false, retryInterval: TimeSpan.Zero,
|
|
messageId: TrackedOperationId.New().ToString());
|
|
}
|
|
|
|
await service.RetryPendingMessagesAsync();
|
|
|
|
var deadline = DateTime.UtcNow + TimeSpan.FromSeconds(5);
|
|
while (DateTime.UtcNow < deadline && service.ObserverQueueDroppedCount < 10)
|
|
await Task.Delay(10);
|
|
|
|
Assert.True(service.ObserverQueueDroppedCount >= 10,
|
|
"expected many notifications to be dropped once the bounded queue filled");
|
|
|
|
var dropWarnings = logger.Entries
|
|
.Where(e => e.Level == LogLevel.Warning
|
|
&& e.Message.Contains("audit-observer queue", StringComparison.Ordinal))
|
|
.ToList();
|
|
|
|
Assert.True(dropWarnings.Count == 1,
|
|
$"expected exactly one observer-queue-drop Warning per episode (rate-limited), " +
|
|
$"but got {dropWarnings.Count} for {service.ObserverQueueDroppedCount} drops");
|
|
}
|
|
finally
|
|
{
|
|
gate.TrySetResult();
|
|
await service.StopAsync();
|
|
var path = localDb.Path;
|
|
localDb.Dispose();
|
|
TestLocalDb.DeleteFiles(path);
|
|
}
|
|
}
|
|
}
|