diff --git a/src/ServiceControl.Audit.Persistence.EFCore/Implementation/AuditRetention.cs b/src/ServiceControl.Audit.Persistence.EFCore/Implementation/AuditRetention.cs index 277f309d22..588631ee32 100644 --- a/src/ServiceControl.Audit.Persistence.EFCore/Implementation/AuditRetention.cs +++ b/src/ServiceControl.Audit.Persistence.EFCore/Implementation/AuditRetention.cs @@ -69,6 +69,7 @@ async Task Sweep(bool pace, CancellationToken cancellationToken) { try { + DateTime? deferred; await using (var handle = await retentionLock.TryAcquire(cancellationToken)) { if (handle is null) @@ -77,10 +78,18 @@ async Task Sweep(bool pace, CancellationToken cancellationToken) return; } - await RemoveExpired(pace, cancellationToken); + deferred = await RemoveExpired(pace, cancellationToken); } - retentionState.SweepSucceeded(); + // A table that stays too busy to drop keeps every expired row, so it counts against the check like an error. + if (deferred is { } start) + { + retentionState.SweepFailed($"The audit tables were too busy to drop the rows from {start:u}."); + } + else + { + retentionState.SweepSucceeded(); + } } #pragma warning disable PS0019 // Filtered on the token alone because SqlClient reports a cancelled command as a SqlException. catch (Exception ex) when (!cancellationToken.IsCancellationRequested) @@ -91,7 +100,8 @@ async Task Sweep(bool pace, CancellationToken cancellationToken) #pragma warning restore PS0019 } - async Task RemoveExpired(bool pace, CancellationToken cancellationToken) + // Returns the start of the expired rows it had to leave because the tables were too busy, or null when it removed them all. + async Task RemoveExpired(bool pace, CancellationToken cancellationToken) { await using var scope = scopeFactory.CreateAsyncScope(); var dbContext = scope.ServiceProvider.GetRequiredService(); @@ -112,7 +122,7 @@ async Task RemoveExpired(bool pace, CancellationToken cancellationToken) if (drop.Deferred) { logger.LogInformation("Left the audit rows from {Start:u} for the next sweep because the audit tables were too busy to drop them", expired); - return; + return expired; } if (pace && !drop.Completed) @@ -123,5 +133,7 @@ async Task RemoveExpired(bool pace, CancellationToken cancellationToken) logger.LogDebug("Removed the expired audit rows from {Start:u}", expired); } + + return null; } } diff --git a/src/ServiceControl.Audit.Persistence.Tests/EFCore/EFRetentionCustomCheckTests.cs b/src/ServiceControl.Audit.Persistence.Tests/EFCore/EFRetentionCustomCheckTests.cs index 66b698c25f..fa342f4a46 100644 --- a/src/ServiceControl.Audit.Persistence.Tests/EFCore/EFRetentionCustomCheckTests.cs +++ b/src/ServiceControl.Audit.Persistence.Tests/EFCore/EFRetentionCustomCheckTests.cs @@ -1,12 +1,14 @@ namespace ServiceControl.Audit.Persistence.Tests { using System; + using System.Collections.Generic; using System.Linq; using System.Threading; using System.Threading.Tasks; using Microsoft.Extensions.DependencyInjection; using NServiceBus.CustomChecks; using NUnit.Framework; + using ServiceControl.Audit.Persistence.EFCore.DbContexts; using ServiceControl.Audit.Persistence.EFCore.Implementation; using ServiceControl.Audit.Persistence.EFCore.Infrastructure; @@ -33,6 +35,25 @@ public async Task Check_fails_once_three_consecutive_sweeps_have_failed() } } + [Test] + public async Task Check_fails_once_three_consecutive_sweeps_have_left_expired_rows_behind() + { + var retention = ActivatorUtilities.CreateInstance(ServiceProvider, new BusyPartitions()); + + await retention.SweepNow(); + await retention.SweepNow(); + var afterTwo = await Check.PerformCheck(); + await retention.SweepNow(); + var afterThree = await Check.PerformCheck(); + + using (Assert.EnterMultipleScope()) + { + Assert.That(afterTwo.HasFailed, Is.False); + Assert.That(afterThree.HasFailed, Is.True); + Assert.That(afterThree.FailureReason, Does.Contain("too busy")); + } + } + [Test] public async Task A_successful_sweep_clears_the_failure() { @@ -76,5 +97,22 @@ sealed class UnreachableRetentionLock : IRetentionLock public Task TryAcquire(CancellationToken cancellationToken = default) => Task.FromException(new InvalidOperationException(Reason)); } + + // Has one expired day that can never be dropped, like a partition another session keeps locked. + sealed class BusyPartitions : IAuditPartitionManager + { + static readonly DateTime ExpiredDay = new(2020, 1, 1, 0, 0, 0, DateTimeKind.Utc); + + public Task EnsurePartitions(AuditDbContext dbContext, DateTime from, DateTime toExclusive, CancellationToken cancellationToken = default) => Task.CompletedTask; + + public Task> ListExpired(AuditDbContext dbContext, DateTime keepFrom, CancellationToken cancellationToken = default) => + Task.FromResult>([ExpiredDay]); + + public Task DropExpired(AuditDbContext dbContext, DateTime start, int batchSize, CancellationToken cancellationToken = default) => + Task.FromResult(new DropResult(RowsDeleted: 0, Completed: true, Deferred: true)); + + public Task ProvisionedUntil(AuditDbContext dbContext, CancellationToken cancellationToken = default) => + Task.FromResult(null); + } } }