diff --git a/src/ServiceControl.Audit.Persistence.Tests.RavenDB/PersistenceTestsConfiguration.cs b/src/ServiceControl.Audit.Persistence.Tests.RavenDB/PersistenceTestsConfiguration.cs index cc4a3808ed..d42f69b627 100644 --- a/src/ServiceControl.Audit.Persistence.Tests.RavenDB/PersistenceTestsConfiguration.cs +++ b/src/ServiceControl.Audit.Persistence.Tests.RavenDB/PersistenceTestsConfiguration.cs @@ -95,11 +95,7 @@ public async Task Configure(Action setSettings) AuditIngestionUnitOfWorkFactory = host.Services.GetRequiredService(); } - public Task CompleteDBOperation() - { - DocumentStore.WaitForIndexing(); - return Task.CompletedTask; - } + public Task CompleteDBOperation() => DocumentStore.WaitForIndexingAsync(); public async Task Cleanup() { diff --git a/src/ServiceControl.Audit.Persistence.Tests.RavenDB/RavenIndexAwaiter.cs b/src/ServiceControl.Audit.Persistence.Tests.RavenDB/RavenIndexAwaiter.cs index 5649ee6054..904bc59d15 100644 --- a/src/ServiceControl.Audit.Persistence.Tests.RavenDB/RavenIndexAwaiter.cs +++ b/src/ServiceControl.Audit.Persistence.Tests.RavenDB/RavenIndexAwaiter.cs @@ -1,18 +1,53 @@ using System; +using System.Diagnostics; +using System.Linq; using System.Threading; +using System.Threading.Tasks; using NUnit.Framework; using Raven.Client.Documents; +using Raven.Client.Documents.Indexes; using Raven.Client.Documents.Operations; +using Raven.Client.Documents.Operations.Indexes; public static class RavenIndexAwaiter { - public static void WaitForIndexing(this IDocumentStore store) - { - store.WaitForIndexing(10); - } + // CI runners can be slow. Three new indexes on a fresh database have been seen to take more than 10 seconds for + // their first indexing pass on a Windows runner. The wait returns as soon as the indexes are up to date, so a + // large budget only costs time when something is actually wrong. + static readonly TimeSpan DefaultTimeout = TimeSpan.FromSeconds(60); + static readonly TimeSpan PollInterval = TimeSpan.FromMilliseconds(100); - static void WaitForIndexing(this IDocumentStore store, int secondsToWait) + public static Task WaitForIndexingAsync(this IDocumentStore store, CancellationToken cancellationToken = default) => + store.WaitForIndexingAsync(DefaultTimeout, cancellationToken); + + public static async Task WaitForIndexingAsync(this IDocumentStore store, TimeSpan timeout, CancellationToken cancellationToken = default) { - Assert.That(SpinWait.SpinUntil(() => store.Maintenance.Send(new GetStatisticsOperation()).StaleIndexes.Length == 0, TimeSpan.FromSeconds(secondsToWait)), Is.True); + var stopwatch = Stopwatch.StartNew(); + IndexStats[] stats; + + do + { + stats = await store.Maintenance.SendAsync(new GetIndexesStatisticsOperation(), cancellationToken); + + // An index in the error state never becomes up to date. Fail now with the errors instead of after the timeout. + var erroredIndexes = stats.Where(i => i.State == IndexState.Error || i.ErrorsCount > 0).Select(i => i.Name).ToArray(); + if (erroredIndexes.Length > 0) + { + var errors = await store.Maintenance.SendAsync(new GetIndexErrorsOperation(erroredIndexes), cancellationToken); + var details = errors.SelectMany(e => e.Errors.Select(x => $"{e.Name}: {x.Action} {x.Document} {x.Error}")); + Assert.Fail($"Indexes have errors:{Environment.NewLine}{string.Join(Environment.NewLine, details)}"); + } + + if (stats.All(i => !i.IsStale)) + { + return; + } + + await Task.Delay(PollInterval, cancellationToken); + } + while (stopwatch.Elapsed < timeout); + + var stale = stats.Where(i => i.IsStale).Select(i => $"{i.Name} (state: {i.State}, status: {i.Status}, entries: {i.EntriesCount})"); + Assert.Fail($"Indexes were still stale after {timeout}:{Environment.NewLine}{string.Join(Environment.NewLine, stale)}"); } -} \ No newline at end of file +} diff --git a/src/ServiceControl.Persistence.Tests.RavenDB/CompositeViews/MessagesViewTests.cs b/src/ServiceControl.Persistence.Tests.RavenDB/CompositeViews/MessagesViewTests.cs index 6d6dca3bd2..d695e0dfb9 100644 --- a/src/ServiceControl.Persistence.Tests.RavenDB/CompositeViews/MessagesViewTests.cs +++ b/src/ServiceControl.Persistence.Tests.RavenDB/CompositeViews/MessagesViewTests.cs @@ -17,7 +17,7 @@ class MessagesViewTests : RavenPersistenceTestBase { [Test] - public void Filter_out_system_messages() + public async Task Filter_out_system_messages() { using (var session = DocumentStore.OpenSession()) { @@ -40,7 +40,7 @@ public void Filter_out_system_messages() session.SaveChanges(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using (var session = DocumentStore.OpenSession()) { @@ -55,7 +55,7 @@ public void Filter_out_system_messages() } [Test] - public void Order_by_critical_time() + public async Task Order_by_critical_time() { using (var session = DocumentStore.OpenSession()) { @@ -87,7 +87,7 @@ public void Order_by_critical_time() session.SaveChanges(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using (var session = DocumentStore.OpenSession()) { @@ -109,7 +109,7 @@ public void Order_by_critical_time() } [Test] - public void Order_by_time_sent() + public async Task Order_by_time_sent() { using (var session = DocumentStore.OpenSession()) { @@ -134,7 +134,7 @@ public void Order_by_time_sent() session.SaveChanges(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using (var session = DocumentStore.OpenSession()) { @@ -184,7 +184,7 @@ public async Task TimeSent_is_not_cast_to_DateTimeMin_if_null() session.SaveChanges(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using (var session = DocumentStore.OpenAsyncSession()) { @@ -232,7 +232,7 @@ public async Task Correct_status_for_failed_messages(FailedMessageStatus failedM session.SaveChanges(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using (var session = DocumentStore.OpenAsyncSession()) { @@ -275,7 +275,7 @@ public async Task Correct_status_for_repeated_errors() session.SaveChanges(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using (var session = DocumentStore.OpenAsyncSession()) { diff --git a/src/ServiceControl.Persistence.Tests.RavenDB/Infrastructure/RavenIndexAwaiter.cs b/src/ServiceControl.Persistence.Tests.RavenDB/Infrastructure/RavenIndexAwaiter.cs index 8f93a65df6..904bc59d15 100644 --- a/src/ServiceControl.Persistence.Tests.RavenDB/Infrastructure/RavenIndexAwaiter.cs +++ b/src/ServiceControl.Persistence.Tests.RavenDB/Infrastructure/RavenIndexAwaiter.cs @@ -1,21 +1,53 @@ using System; +using System.Diagnostics; +using System.Linq; using System.Threading; +using System.Threading.Tasks; using NUnit.Framework; using Raven.Client.Documents; +using Raven.Client.Documents.Indexes; using Raven.Client.Documents.Operations; +using Raven.Client.Documents.Operations.Indexes; public static class RavenIndexAwaiter { - public static void WaitForIndexing(this IDocumentStore store) => store.WaitForIndexing(10); + // CI runners can be slow. Three new indexes on a fresh database have been seen to take more than 10 seconds for + // their first indexing pass on a Windows runner. The wait returns as soon as the indexes are up to date, so a + // large budget only costs time when something is actually wrong. + static readonly TimeSpan DefaultTimeout = TimeSpan.FromSeconds(60); + static readonly TimeSpan PollInterval = TimeSpan.FromMilliseconds(100); - static void WaitForIndexing(this IDocumentStore store, int secondsToWait) + public static Task WaitForIndexingAsync(this IDocumentStore store, CancellationToken cancellationToken = default) => + store.WaitForIndexingAsync(DefaultTimeout, cancellationToken); + + public static async Task WaitForIndexingAsync(this IDocumentStore store, TimeSpan timeout, CancellationToken cancellationToken = default) { - var getStatisticsCommand = new GetStatisticsOperation(); - Assert.That(SpinWait.SpinUntil(() => + var stopwatch = Stopwatch.StartNew(); + IndexStats[] stats; + + do { - var stats = store.Maintenance.Send(getStatisticsCommand); + stats = await store.Maintenance.SendAsync(new GetIndexesStatisticsOperation(), cancellationToken); + + // An index in the error state never becomes up to date. Fail now with the errors instead of after the timeout. + var erroredIndexes = stats.Where(i => i.State == IndexState.Error || i.ErrorsCount > 0).Select(i => i.Name).ToArray(); + if (erroredIndexes.Length > 0) + { + var errors = await store.Maintenance.SendAsync(new GetIndexErrorsOperation(erroredIndexes), cancellationToken); + var details = errors.SelectMany(e => e.Errors.Select(x => $"{e.Name}: {x.Action} {x.Document} {x.Error}")); + Assert.Fail($"Indexes have errors:{Environment.NewLine}{string.Join(Environment.NewLine, details)}"); + } + + if (stats.All(i => !i.IsStale)) + { + return; + } + + await Task.Delay(PollInterval, cancellationToken); + } + while (stopwatch.Elapsed < timeout); - return stats.StaleIndexes.Length == 0; - }, TimeSpan.FromSeconds(secondsToWait)), Is.True); + var stale = stats.Where(i => i.IsStale).Select(i => $"{i.Name} (state: {i.State}, status: {i.Status}, entries: {i.EntriesCount})"); + Assert.Fail($"Indexes were still stale after {timeout}:{Environment.NewLine}{string.Join(Environment.NewLine, stale)}"); } -} \ No newline at end of file +} diff --git a/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportCustomCheckTests.cs b/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportCustomCheckTests.cs index 4231f209d7..05c7ec562b 100644 --- a/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportCustomCheckTests.cs +++ b/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportCustomCheckTests.cs @@ -44,7 +44,7 @@ await session.StoreAsync(new FailedErrorImport await session.SaveChangesAsync(); } - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); var customCheck = ServiceProvider.GetRequiredService(); diff --git a/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportDedupeTests.cs b/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportDedupeTests.cs index 7f9ec7694b..67fe655370 100644 --- a/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportDedupeTests.cs +++ b/src/ServiceControl.Persistence.Tests.RavenDB/Operations/FailedErrorImportDedupeTests.cs @@ -22,7 +22,7 @@ public async Task Repeated_failure_of_the_same_message_stores_one_document() await StoreFailure(headers, "the first failure"); await StoreFailure(headers, "the second failure"); - DocumentStore.WaitForIndexing(); + await DocumentStore.WaitForIndexingAsync(); using var session = DocumentStore.OpenAsyncSession(); var documents = await session.Query().ToListAsync(); diff --git a/src/ServiceControl.Persistence.Tests.RavenDB/PersistenceTestsContext.cs b/src/ServiceControl.Persistence.Tests.RavenDB/PersistenceTestsContext.cs index 5bcae71f20..84800e06bf 100644 --- a/src/ServiceControl.Persistence.Tests.RavenDB/PersistenceTestsContext.cs +++ b/src/ServiceControl.Persistence.Tests.RavenDB/PersistenceTestsContext.cs @@ -92,11 +92,7 @@ public async Task InsertFailedMessages(params FailedMessage[] messages) public DateTime UtcNow => FakeTime.GetUtcNow().UtcDateTime; - public Task CompleteDatabaseOperation() - { - DocumentStore.WaitForIndexing(); - return Task.CompletedTask; - } + public Task CompleteDatabaseOperation() => DocumentStore.WaitForIndexingAsync(); [Conditional("DEBUG")] public void BlockToInspectDatabase()