From 763f5d0274cf46927d89aaa233415f7628a1d8b2 Mon Sep 17 00:00:00 2001 From: Andrei Grigorev Date: Fri, 9 Nov 2018 18:52:57 -0800 Subject: [PATCH 1/2] Quickfix for ValidateCertificate job issue (#668) * Quickfix for ValidateCertificate job issue * Validation.Common.Job update instead of ValidateCertificate --- src/Validation.Common.Job/Validation.Common.Job.csproj | 3 +++ .../Validation.PackageSigning.ValidateCertificate.csproj | 2 +- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/src/Validation.Common.Job/Validation.Common.Job.csproj b/src/Validation.Common.Job/Validation.Common.Job.csproj index 19424a83b..57a0e09f8 100644 --- a/src/Validation.Common.Job/Validation.Common.Job.csproj +++ b/src/Validation.Common.Job/Validation.Common.Job.csproj @@ -99,6 +99,9 @@ runtime; build; native; contentfiles; analyzers all + + 2.33.0 + 2.33.0 diff --git a/src/Validation.PackageSigning.ValidateCertificate/Validation.PackageSigning.ValidateCertificate.csproj b/src/Validation.PackageSigning.ValidateCertificate/Validation.PackageSigning.ValidateCertificate.csproj index 1905054d7..b9b4a6506 100644 --- a/src/Validation.PackageSigning.ValidateCertificate/Validation.PackageSigning.ValidateCertificate.csproj +++ b/src/Validation.PackageSigning.ValidateCertificate/Validation.PackageSigning.ValidateCertificate.csproj @@ -106,7 +106,7 @@ - + From 297a5cf12c80bdb87f4dc9b3a4ec29cc01ee9ddb Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lo=C3=AFc=20Sharma?= Date: Thu, 15 Nov 2018 13:32:20 -0800 Subject: [PATCH 2/2] [Revalidation] Improve throughput by batching revalidations (#667) Increase the throughput of the revalidation job by batching revalidations. The revalidation job does a bunch of work before enqueueing revalidations as it must: 1. Ensure the revalidation job hasn't been killswitched 2. Verify that the ingestion pipeline is healthy 3. Verify that the desired package event rate hasn't been reached This change amortizes that work by enqueueing revalidations in batches. Also, the job now takes into account how long it spent enqueueing revalidations when deciding how long to sleep for. Addresses https://github.com/NuGet/Engineering/issues/1877 --- .../RevalidationQueueConfiguration.cs | 14 +- .../NuGet.Services.Revalidate.csproj | 3 +- .../IPackageRevalidationStateService.cs | 8 +- .../Services/IRevalidationQueue.cs | 7 +- .../Services/IRevalidationStarter.cs | 2 +- .../Services/IRevalidationThrottler.cs | 5 +- .../Services/ITelemetryService.cs | 3 + .../PackageRevalidationStateService.cs | 14 +- .../Services/RevalidationOperation.cs | 9 +- .../Services/RevalidationQueue.cs | 173 +++++++++++------- .../Services/RevalidationService.cs | 26 ++- .../Services/RevalidationStarter.cs | 79 +++++--- .../Services/RevalidationThrottler.cs | 16 +- .../Services/StartRevalidationResult.cs | 54 ++++++ ...onResult.cs => StartRevalidationStatus.cs} | 10 +- .../Services/TelemetryService.cs | 6 + .../Settings/dev.json | 5 +- .../Settings/int.json | 5 +- .../Settings/prod.json | 5 +- src/StatusAggregator/StatusAggregator.csproj | 6 +- .../Validation.ScanAndSign.Core.csproj | 2 +- .../Services/RevalidationQueueFacts.cs | 129 +++++++++---- .../Services/RevalidationServiceFacts.cs | 41 +---- .../Services/RevalidationStarterFacts.cs | 113 +++++++----- 24 files changed, 477 insertions(+), 258 deletions(-) create mode 100644 src/NuGet.Services.Revalidate/Services/StartRevalidationResult.cs rename src/NuGet.Services.Revalidate/Services/{RevalidationResult.cs => StartRevalidationStatus.cs} (69%) diff --git a/src/NuGet.Services.Revalidate/Configuration/RevalidationQueueConfiguration.cs b/src/NuGet.Services.Revalidate/Configuration/RevalidationQueueConfiguration.cs index 8ec213a7e..b97b010d2 100644 --- a/src/NuGet.Services.Revalidate/Configuration/RevalidationQueueConfiguration.cs +++ b/src/NuGet.Services.Revalidate/Configuration/RevalidationQueueConfiguration.cs @@ -8,19 +8,13 @@ namespace NuGet.Services.Revalidate public class RevalidationQueueConfiguration { /// - /// If non-null, this skips revalidations of packages with more than this many versions. + /// The maximum number of revalidations that should be returned by . /// - public int? MaximumPackageVersions { get; set; } + public int MaxBatchSize { get; set; } = 64; /// - /// The maximum times that the should look for a revalidation - /// before giving up. - /// - public int MaximumAttempts { get; set; } = 5; - - /// - /// The time to sleep after an initialized revalidation is deemed completed. + /// If non-null, this skips revalidations of packages with more than this many versions. /// - public TimeSpan SleepBetweenAttempts { get; set; } = TimeSpan.FromSeconds(5); + public int? MaximumPackageVersions { get; set; } } } diff --git a/src/NuGet.Services.Revalidate/NuGet.Services.Revalidate.csproj b/src/NuGet.Services.Revalidate/NuGet.Services.Revalidate.csproj index cc346109f..762cc12e5 100644 --- a/src/NuGet.Services.Revalidate/NuGet.Services.Revalidate.csproj +++ b/src/NuGet.Services.Revalidate/NuGet.Services.Revalidate.csproj @@ -69,7 +69,7 @@ - + @@ -82,6 +82,7 @@ + diff --git a/src/NuGet.Services.Revalidate/Services/IPackageRevalidationStateService.cs b/src/NuGet.Services.Revalidate/Services/IPackageRevalidationStateService.cs index f72e09ecc..3a1019b1b 100644 --- a/src/NuGet.Services.Revalidate/Services/IPackageRevalidationStateService.cs +++ b/src/NuGet.Services.Revalidate/Services/IPackageRevalidationStateService.cs @@ -34,10 +34,10 @@ public interface IPackageRevalidationStateService Task CountRevalidationsEnqueuedInPastHourAsync(); /// - /// Update the package revalidation and mark is as enqueued. + /// Update the package revalidations and mark them as enqueued. /// - /// The revalidation to update. - /// A task that completes once the revalidation has been updated. - Task MarkPackageRevalidationAsEnqueuedAsync(PackageRevalidation revalidation); + /// The revalidations to update. + /// A task that completes once the revalidations have been updated. + Task MarkPackageRevalidationsAsEnqueuedAsync(IReadOnlyList revalidations); } } diff --git a/src/NuGet.Services.Revalidate/Services/IRevalidationQueue.cs b/src/NuGet.Services.Revalidate/Services/IRevalidationQueue.cs index 7ff6e7fbf..31f879540 100644 --- a/src/NuGet.Services.Revalidate/Services/IRevalidationQueue.cs +++ b/src/NuGet.Services.Revalidate/Services/IRevalidationQueue.cs @@ -1,6 +1,7 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. +using System.Collections.Generic; using System.Threading.Tasks; using NuGet.Services.Validation; @@ -9,9 +10,9 @@ namespace NuGet.Services.Revalidate public interface IRevalidationQueue { /// - /// Fetch the next package to revalidate. + /// Fetch the next packages to revalidate. /// - /// The next package to revalidate, or null if there are no packages to revalidate at this time. - Task NextOrNullAsync(); + /// The next packages to revalidate, or an empty list if there are no packages to revalidate at this time. + Task> NextAsync(); } } diff --git a/src/NuGet.Services.Revalidate/Services/IRevalidationStarter.cs b/src/NuGet.Services.Revalidate/Services/IRevalidationStarter.cs index baa2b3ce6..2e9aac758 100644 --- a/src/NuGet.Services.Revalidate/Services/IRevalidationStarter.cs +++ b/src/NuGet.Services.Revalidate/Services/IRevalidationStarter.cs @@ -20,6 +20,6 @@ public interface IRevalidationStarter /// 4. A revalidation could not be found at this time /// /// The result of the revalidation attempt. - Task StartNextRevalidationAsync(); + Task StartNextRevalidationsAsync(); } } diff --git a/src/NuGet.Services.Revalidate/Services/IRevalidationThrottler.cs b/src/NuGet.Services.Revalidate/Services/IRevalidationThrottler.cs index e1870321f..535cf69b7 100644 --- a/src/NuGet.Services.Revalidate/Services/IRevalidationThrottler.cs +++ b/src/NuGet.Services.Revalidate/Services/IRevalidationThrottler.cs @@ -1,6 +1,7 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. +using System; using System.Threading.Tasks; namespace NuGet.Services.Revalidate @@ -16,8 +17,10 @@ public interface IRevalidationThrottler /// /// Delay the current task to achieve the desired revalidation rate. /// + /// The number of revalidations started. + /// How long it took it took to start the revalidations. /// Delay the task to ensure the desired revalidation rate. - Task DelayUntilNextRevalidationAsync(); + Task DelayUntilNextRevalidationAsync(int started, TimeSpan startDuration); /// /// Delay the current task until when a revalidation can be retried. diff --git a/src/NuGet.Services.Revalidate/Services/ITelemetryService.cs b/src/NuGet.Services.Revalidate/Services/ITelemetryService.cs index 881578911..50dec2f16 100644 --- a/src/NuGet.Services.Revalidate/Services/ITelemetryService.cs +++ b/src/NuGet.Services.Revalidate/Services/ITelemetryService.cs @@ -1,12 +1,15 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. +using System; using NuGet.Services.Logging; namespace NuGet.Services.Revalidate { public interface ITelemetryService { + IDisposable TrackFindNextRevalidations(); + DurationMetric TrackStartNextRevalidationOperation(); void TrackPackageRevalidationMarkedAsCompleted(string packageId, string normalizedVersion); diff --git a/src/NuGet.Services.Revalidate/Services/PackageRevalidationStateService.cs b/src/NuGet.Services.Revalidate/Services/PackageRevalidationStateService.cs index fb90b8497..b6edde99e 100644 --- a/src/NuGet.Services.Revalidate/Services/PackageRevalidationStateService.cs +++ b/src/NuGet.Services.Revalidate/Services/PackageRevalidationStateService.cs @@ -67,21 +67,21 @@ public async Task CountRevalidationsEnqueuedInPastHourAsync() .CountAsync(); } - public async Task MarkPackageRevalidationAsEnqueuedAsync(PackageRevalidation revalidation) + public async Task MarkPackageRevalidationsAsEnqueuedAsync(IReadOnlyList revalidations) { try { - revalidation.Enqueued = DateTime.UtcNow; + var enqueueTime = DateTime.UtcNow; + foreach (var revalidation in revalidations) + { + revalidation.Enqueued = enqueueTime; + } await _context.SaveChangesAsync(); } catch (DbUpdateConcurrencyException) { - _logger.LogWarning( - "Failed to update revalidation as enqueued for {PackageId} {PackageNormalizedVersion}", - revalidation.PackageId, - revalidation.PackageNormalizedVersion); - + _logger.LogWarning("Failed to update revalidations as enqueued"); throw; } } diff --git a/src/NuGet.Services.Revalidate/Services/RevalidationOperation.cs b/src/NuGet.Services.Revalidate/Services/RevalidationOperation.cs index 9a85e08cc..c1b64690b 100644 --- a/src/NuGet.Services.Revalidate/Services/RevalidationOperation.cs +++ b/src/NuGet.Services.Revalidate/Services/RevalidationOperation.cs @@ -6,8 +6,13 @@ namespace NuGet.Services.Revalidate public class StartNextRevalidationOperation { /// - /// The result of attempting to start the next revalidation. + /// The result of attempting to start the next revalidations. /// - public RevalidationResult Result { get; set; } + public StartRevalidationStatus Result { get; set; } + + /// + /// The number of revalidations started. + /// + public int Started { get; set; } } } diff --git a/src/NuGet.Services.Revalidate/Services/RevalidationQueue.cs b/src/NuGet.Services.Revalidate/Services/RevalidationQueue.cs index be14a279c..26ccd57e1 100644 --- a/src/NuGet.Services.Revalidate/Services/RevalidationQueue.cs +++ b/src/NuGet.Services.Revalidate/Services/RevalidationQueue.cs @@ -2,6 +2,7 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. using System; +using System.Collections.Generic; using System.Data.Entity; using System.Data.Entity.Infrastructure; using System.Linq; @@ -37,19 +38,17 @@ public RevalidationQueue( _logger = logger ?? throw new ArgumentNullException(nameof(logger)); } - public async Task NextOrNullAsync() + public async Task> NextAsync() { - for (var i = 0; i < _config.MaximumAttempts; i++) + // Find the next package to revalidate. We will skip packages if: + // 1. The package has more than "MaximumPackageVersions" versions + // 2. The package has already been enqueued for revalidation + // 3. The package's revalidation was completed by an external factory (like manual admin revalidation) + List next; + using (_telemetry.TrackFindNextRevalidations()) { - _logger.LogInformation( - "Attempting to find the next revalidation. Try {Attempt} of {MaxAttempts}", - i + 1, - _config.MaximumAttempts); - - // Find the next package to revalidate. We will skip packages if: - // 1. The package has more than "MaximumPackageVersions" versions - // 2. The package has already been enqueued for revalidation - // 3. The package's revalidation was completed by an external factory (like manual admin revalidation) + _logger.LogInformation("Finding the next packages to revalidate..."); + IQueryable query = _validationContext.PackageRevalidations; if (_config.MaximumPackageVersions.HasValue) @@ -61,82 +60,130 @@ public async Task NextOrNullAsync() .Any(g => g.Key == r.PackageId)); } - var next = await query + next = await query .Where(r => r.Enqueued == null) .Where(r => r.Completed == false) .OrderBy(r => r.Key) - .FirstOrDefaultAsync(); + .Take(_config.MaxBatchSize) + .ToListAsync(); + } - if (next == null) - { - _logger.LogWarning("Could not find any incomplete revalidations"); - return null; - } + _logger.LogInformation("Found {Revalidations} packages to revalidate", next.Count); - // Don't revalidate packages that already have a repository signature or that no longer exist. - if (await HasRepositorySignature(next) || await IsDeleted(next)) - { - await MarkAsCompleted(next); - await Task.Delay(_config.SleepBetweenAttempts); + // Return all the revalidations that aren't already completed. + return await FilterCompletedRevalidationsAsync(next); + } - continue; - } + private async Task> FilterCompletedRevalidationsAsync(IReadOnlyList revalidations) + { + if (!revalidations.Any()) + { + return revalidations; + } - _logger.LogInformation( - "Found revalidation for {PackageId} {PackageNormalizedVersion} after {Attempt} attempts", - next.PackageId, - next.PackageNormalizedVersion, - i + 1); + var completed = new List(); + var uncompleted = revalidations.ToDictionary( + r => $"{r.PackageId}/{r.PackageNormalizedVersion}", + r => r); - return next; - } + // Packages that already have a repository signature do not need to be revalidated. + _logger.LogInformation("Finding revalidations that can be skipped because their packages are already repository signed..."); + + var hasRepositorySignatures = await _validationContext.PackageSigningStates + .Select(s => new { + IdAndVersion = s.PackageId + "/" + s.PackageNormalizedVersion, + s.PackageSignatures + }) + .Where(s => uncompleted.Keys.Contains(s.IdAndVersion)) + .Where(s => s.PackageSignatures.Any(sig => sig.Type == PackageSignatureType.Repository)) + .Select(s => s.IdAndVersion) + .ToListAsync(); _logger.LogInformation( - "Did not find any revalidations after {MaxAttempts}. Retry later...", - _config.MaximumAttempts); + "Found {RevalidationCount} revalidations that can be skipped because their packages are already repository signed", + hasRepositorySignatures.Count); - return null; - } + foreach (var idAndVersion in hasRepositorySignatures) + { + completed.Add(uncompleted[idAndVersion]); + uncompleted.Remove(idAndVersion); + } - private Task HasRepositorySignature(PackageRevalidation revalidation) - { - return _validationContext.PackageSigningStates - .Where(s => s.PackageId == revalidation.PackageId) - .Where(s => s.PackageNormalizedVersion == revalidation.PackageNormalizedVersion) - .Where(s => s.PackageSignatures.Any(sig => sig.Type == PackageSignatureType.Repository)) - .AnyAsync(); - } + // Packages that are no longer available should not be revalidated. + _logger.LogInformation("Finding revalidations' package statuses..."); - private async Task IsDeleted(PackageRevalidation revalidation) - { - var packageStatus = await _galleryContext.Set() - .Where(p => p.PackageRegistration.Id == revalidation.PackageId) - .Where(p => p.NormalizedVersion == revalidation.PackageNormalizedVersion) - .Select(p => (PackageStatus?)p.PackageStatusKey) - .FirstOrDefaultAsync(); + var packageStatuses = await _galleryContext.Set() + .Select(p => new + { + Identity = p.PackageRegistration.Id + "/" + p.NormalizedVersion, + p.PackageStatusKey + }) + .Where(p => uncompleted.Keys.Contains(p.Identity)) + .ToDictionaryAsync( + p => p.Identity, + p => p.PackageStatusKey); - return (packageStatus == null || packageStatus == PackageStatus.Deleted); - } + _logger.LogInformation("Found {PackageStatusCount} revalidations' package statuses", packageStatuses.Count); + + foreach (var key in uncompleted.Keys.ToList()) + { + // Packages that are hard deleted won't have a status. + if (!packageStatuses.TryGetValue(key, out var status) || status == PackageStatus.Deleted) + { + completed.Add(uncompleted[key]); + uncompleted.Remove(key); + continue; + } + } - private async Task MarkAsCompleted(PackageRevalidation revalidation) - { _logger.LogInformation( - "Marking package revalidation as completed as it has a repository signature or is deleted for {PackageId} {PackageNormalizedVersion}", - revalidation.PackageId, - revalidation.PackageNormalizedVersion); + "Found {CompletedRevalidations} revalidations that can be skipped. There are {UncompletedRevalidations} " + + "revalidations remaining in this batch", + completed.Count, + uncompleted.Count); + // Update revalidations that were determined to be completed and return the remaining revalidations. + if (completed.Any()) + { + await MarkRevalidationsAsCompletedAsync(completed); + } + + return uncompleted.Values.ToList(); + } + + private async Task MarkRevalidationsAsCompletedAsync(IReadOnlyList revalidations) + { try { - revalidation.Completed = true; + foreach (var revalidation in revalidations) + { + _logger.LogInformation( + "Marking package {PackageId} {PackageNormalizedVersion} revalidation as completed as the package is unavailable or the package is already repository signed...", + revalidation.PackageId, + revalidation.PackageNormalizedVersion); + + revalidation.Completed = true; + } await _validationContext.SaveChangesAsync(); - _telemetry.TrackPackageRevalidationMarkedAsCompleted(revalidation.PackageId, revalidation.PackageNormalizedVersion); + foreach (var revalidation in revalidations) + { + _logger.LogInformation( + "Marked package {PackageId} {PackageNormalizedVersion} revalidation as completed", + revalidation.PackageId, + revalidation.PackageNormalizedVersion); + + _telemetry.TrackPackageRevalidationMarkedAsCompleted(revalidation.PackageId, revalidation.PackageNormalizedVersion); + } } - catch (DbUpdateConcurrencyException) + catch (DbUpdateConcurrencyException e) { - // Swallow concurrency exceptions. The package will be marked as completed - // on the next iteration of "NextOrNullAsync". + _logger.LogError( + 0, + e, + "Failed to mark package revalidations as completed. " + + $"These revalidations will be marked as completed on the next iteration of {nameof(NextAsync)}..."); } } } diff --git a/src/NuGet.Services.Revalidate/Services/RevalidationService.cs b/src/NuGet.Services.Revalidate/Services/RevalidationService.cs index fb9e40291..c06bd2321 100644 --- a/src/NuGet.Services.Revalidate/Services/RevalidationService.cs +++ b/src/NuGet.Services.Revalidate/Services/RevalidationService.cs @@ -49,23 +49,28 @@ public async Task RunAsync() { _logger.LogInformation("Starting next revalidation..."); - var result = await StartNextRevalidationAsync(); + var startRevalidationsStopwatch = Stopwatch.StartNew(); + var result = await StartNextRevalidationsAsync(); + startRevalidationsStopwatch.Stop(); - switch (result) + switch (result.Status) { - case RevalidationResult.RevalidationEnqueued: - _logger.LogInformation("Successfully enqueued revalidation"); + case StartRevalidationStatus.RevalidationsEnqueued: + _logger.LogInformation( + "Successfully enqueued {RevalidationsStarted} revalidations in {Duration}", + result.RevalidationsStarted, + startRevalidationsStopwatch.Elapsed); - await _throttler.DelayUntilNextRevalidationAsync(); + await _throttler.DelayUntilNextRevalidationAsync(result.RevalidationsStarted, startRevalidationsStopwatch.Elapsed); break; - case RevalidationResult.RetryLater: + case StartRevalidationStatus.RetryLater: _logger.LogInformation("Could not start revalidation, retrying later"); await _throttler.DelayUntilRevalidationRetryAsync(); break; - case RevalidationResult.UnrecoverableError: + case StartRevalidationStatus.UnrecoverableError: default: _logger.LogCritical( "Stopping revalidations due to unrecoverable or unknown result {Result}", @@ -79,15 +84,16 @@ public async Task RunAsync() _logger.LogInformation("Finished running after {ElapsedTime}", runTime.Elapsed); } - private async Task StartNextRevalidationAsync() + private async Task StartNextRevalidationsAsync() { using (var operation = _telemetryService.TrackStartNextRevalidationOperation()) using (var scope = _scopeFactory.CreateScope()) { var starter = scope.ServiceProvider.GetRequiredService(); - var result = await starter.StartNextRevalidationAsync(); + var result = await starter.StartNextRevalidationsAsync(); - operation.Properties.Result = result; + operation.Properties.Result = result.Status; + operation.Properties.Started = result.RevalidationsStarted; return result; } diff --git a/src/NuGet.Services.Revalidate/Services/RevalidationStarter.cs b/src/NuGet.Services.Revalidate/Services/RevalidationStarter.cs index a1526ea2b..d743f2d38 100644 --- a/src/NuGet.Services.Revalidate/Services/RevalidationStarter.cs +++ b/src/NuGet.Services.Revalidate/Services/RevalidationStarter.cs @@ -1,4 +1,6 @@ using System; +using System.Collections.Generic; +using System.Linq; using System.Threading.Tasks; using Microsoft.Extensions.Logging; using NuGet.Services.Validation; @@ -39,7 +41,7 @@ public RevalidationStarter( _logger = logger ?? throw new ArgumentNullException(nameof(logger)); } - public async Task StartNextRevalidationAsync() + public async Task StartNextRevalidationsAsync() { try { @@ -52,51 +54,61 @@ public async Task StartNextRevalidationAsync() "Detected that a revalidation should not be started due to result {Result}", checkResult.Value); - return checkResult.Value; + switch (checkResult.Value) + { + case StartRevalidationStatus.RetryLater: + return StartRevalidationResult.RetryLater; + + case StartRevalidationStatus.UnrecoverableError: + return StartRevalidationResult.UnrecoverableError; + + default: + throw new InvalidOperationException($"Unexpected status {checkResult.Value} from {nameof(CanStartRevalidationAsync)}"); + } } - // Everything is in tip-top shape! Increase the throttling quota and start the next revalidation. + // Everything is in tip-top shape! Increase the throttling quota and start the next revalidations. await _jobState.IncreaseDesiredPackageEventRateAsync(); - var revalidation = await _revalidationQueue.NextOrNullAsync(); - if (revalidation == null) + var revalidations = await _revalidationQueue.NextAsync(); + if (!revalidations.Any()) { - _logger.LogInformation("Could not find a package to revalidate at this time, retry later..."); + _logger.LogInformation("Could not find packages to revalidate at this time, retry later..."); - return RevalidationResult.RetryLater; + return StartRevalidationResult.RetryLater; } - return await StartRevalidationAsync(revalidation); + return await StartRevalidationsAsync(revalidations); } catch (Exception e) { _logger.LogError(0, e, "Failed to start next validation due to exception, retry later..."); - return RevalidationResult.RetryLater; + return StartRevalidationResult.RetryLater; } } - private async Task CanStartRevalidationAsync() + private async Task CanStartRevalidationAsync() { if (!await _singletonService.IsSingletonAsync()) { _logger.LogCritical("Detected another instance of the revalidate job, cancelling revalidations!"); - return RevalidationResult.UnrecoverableError; + return StartRevalidationStatus.UnrecoverableError; } if (await _jobState.IsKillswitchActiveAsync()) { _logger.LogWarning("Revalidation killswitch has been activated, retry later..."); - return RevalidationResult.RetryLater; + return StartRevalidationStatus.RetryLater; } if (await _throttler.IsThrottledAsync()) { _logger.LogInformation("Revalidations have reached the desired event rate, retry later..."); - return RevalidationResult.RetryLater; + return StartRevalidationStatus.RetryLater; } if (!await _healthService.IsHealthyAsync()) @@ -105,32 +117,51 @@ public async Task StartNextRevalidationAsync() await _jobState.ResetDesiredPackageEventRateAsync(); - return RevalidationResult.RetryLater; + return StartRevalidationStatus.RetryLater; } if (await _jobState.IsKillswitchActiveAsync()) { _logger.LogWarning("Revalidation killswitch has been activated after the throttle and health check, retry later..."); - return RevalidationResult.RetryLater; + return StartRevalidationStatus.RetryLater; } return null; } - private async Task StartRevalidationAsync(PackageRevalidation revalidation) + private async Task StartRevalidationsAsync(IReadOnlyList revalidations) { - var message = new PackageValidationMessageData( - revalidation.PackageId, - revalidation.PackageNormalizedVersion, - revalidation.ValidationTrackingId.Value); + _logger.LogInformation("Starting {RevalidationCount} revalidations...", revalidations.Count); + + foreach (var revalidation in revalidations) + { + _logger.LogInformation( + "Starting revalidation for package {PackageId} {PackageVersion}...", + revalidation.PackageId, + revalidation.PackageNormalizedVersion); + + var message = new PackageValidationMessageData( + revalidation.PackageId, + revalidation.PackageNormalizedVersion, + revalidation.ValidationTrackingId.Value); + + await _validationEnqueuer.StartValidationAsync(message); + + _telemetryService.TrackPackageRevalidationStarted(revalidation.PackageId, revalidation.PackageNormalizedVersion); + _logger.LogInformation( + "Started revalidation for package {PackageId} {PackageVersion}", + revalidation.PackageId, + revalidation.PackageNormalizedVersion); + } + + _logger.LogInformation("Started {RevalidationCount} revalidations, marking them as enqueued...", revalidations.Count); - await _validationEnqueuer.StartValidationAsync(message); - await _packageState.MarkPackageRevalidationAsEnqueuedAsync(revalidation); + await _packageState.MarkPackageRevalidationsAsEnqueuedAsync(revalidations); - _telemetryService.TrackPackageRevalidationStarted(revalidation.PackageId, revalidation.PackageNormalizedVersion); + _logger.LogInformation("Marked {RevalidationCount} revalidations as enqueued", revalidations.Count); - return RevalidationResult.RevalidationEnqueued; + return StartRevalidationResult.RevalidationsEnqueued(revalidations.Count); } } } diff --git a/src/NuGet.Services.Revalidate/Services/RevalidationThrottler.cs b/src/NuGet.Services.Revalidate/Services/RevalidationThrottler.cs index c0afcfba5..c2d794f12 100644 --- a/src/NuGet.Services.Revalidate/Services/RevalidationThrottler.cs +++ b/src/NuGet.Services.Revalidate/Services/RevalidationThrottler.cs @@ -9,6 +9,8 @@ namespace NuGet.Services.Revalidate { public class RevalidationThrottler : IRevalidationThrottler { + private static readonly TimeSpan MinimumDelayUntilNextRevalidations = TimeSpan.FromSeconds(5); + private readonly IRevalidationJobStateService _jobState; private readonly IPackageRevalidationStateService _packageState; private readonly IGalleryService _gallery; @@ -59,10 +61,20 @@ public async Task IsThrottledAsync() } } - public async Task DelayUntilNextRevalidationAsync() + public async Task DelayUntilNextRevalidationAsync(int revalidationsStarted, TimeSpan startDuration) { var desiredHourlyRate = await _jobState.GetDesiredPackageEventRateAsync(); - var sleepDuration = TimeSpan.FromHours(1.0 / desiredHourlyRate); + + // Calculate the time to sleep. If this batch started 50 revalidations in 30 seconds and we would like + // to achieve 1,000 revalidations per hour, we should sleep for 2.5 minutes: + // + // (50/1000) * 60 - (30/60) = 2.5 + var sleepDuration = TimeSpan.FromHours((float)revalidationsStarted / desiredHourlyRate) - startDuration; + if (sleepDuration < MinimumDelayUntilNextRevalidations) + { + _logger.LogWarning($"The delay until next revalidation is too small, overriding it to {MinimumDelayUntilNextRevalidations}!"); + sleepDuration = MinimumDelayUntilNextRevalidations; + } _logger.LogInformation("Delaying until next revalidation by sleeping for {SleepDuration}...", sleepDuration); diff --git a/src/NuGet.Services.Revalidate/Services/StartRevalidationResult.cs b/src/NuGet.Services.Revalidate/Services/StartRevalidationResult.cs new file mode 100644 index 000000000..6e7d4b32c --- /dev/null +++ b/src/NuGet.Services.Revalidate/Services/StartRevalidationResult.cs @@ -0,0 +1,54 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. + +using System; + +namespace NuGet.Services.Revalidate +{ + /// + /// The result of . + /// + public class StartRevalidationResult + { + /// + /// A revalidation could not be enqueued at this time. The revalidations should be retried later. + /// + public static readonly StartRevalidationResult RetryLater = new StartRevalidationResult(StartRevalidationStatus.RetryLater); + + /// + /// This instance of the revalidation job has reached an unrecoverable state and MUST stop. + /// + public static readonly StartRevalidationResult UnrecoverableError = new StartRevalidationResult(StartRevalidationStatus.UnrecoverableError); + + private StartRevalidationResult(StartRevalidationStatus status, int revalidationsStarted = 0) + { + if (revalidationsStarted < 0) + { + throw new ArgumentOutOfRangeException(nameof(revalidationsStarted)); + } + + Status = status; + RevalidationsStarted = revalidationsStarted; + } + + /// + /// Constructs a result that indicates one or more revalidations were successfully enqueued. + /// + /// The number of revalidations that were enqueued. + /// The constructed revalidation result. + public static StartRevalidationResult RevalidationsEnqueued(int revalidationsStarted) + { + return new StartRevalidationResult(StartRevalidationStatus.RevalidationsEnqueued, revalidationsStarted); + } + + /// + /// The status of starting revalidations. + /// + public StartRevalidationStatus Status { get; } + + /// + /// The number of revalidations that were started. + /// + public int RevalidationsStarted { get; } + } +} diff --git a/src/NuGet.Services.Revalidate/Services/RevalidationResult.cs b/src/NuGet.Services.Revalidate/Services/StartRevalidationStatus.cs similarity index 69% rename from src/NuGet.Services.Revalidate/Services/RevalidationResult.cs rename to src/NuGet.Services.Revalidate/Services/StartRevalidationStatus.cs index 8bed7a7cf..e0f14e4c9 100644 --- a/src/NuGet.Services.Revalidate/Services/RevalidationResult.cs +++ b/src/NuGet.Services.Revalidate/Services/StartRevalidationStatus.cs @@ -4,17 +4,17 @@ namespace NuGet.Services.Revalidate { /// - /// The result from + /// The result from /// - public enum RevalidationResult + public enum StartRevalidationStatus { /// - /// A revalidation was successfully enqueued. + /// One or more revalidations were successfully enqueued. /// - RevalidationEnqueued, + RevalidationsEnqueued, /// - /// A revalidation could not be enqueued at this time. The revalidation should be retried later. + /// A revalidation could not be enqueued at this time. The revalidations should be retried later. /// RetryLater, diff --git a/src/NuGet.Services.Revalidate/Services/TelemetryService.cs b/src/NuGet.Services.Revalidate/Services/TelemetryService.cs index 1ea15a0e6..2ce4fbb20 100644 --- a/src/NuGet.Services.Revalidate/Services/TelemetryService.cs +++ b/src/NuGet.Services.Revalidate/Services/TelemetryService.cs @@ -11,6 +11,7 @@ public class TelemetryService : ITelemetryService { private const string RevalidationPrefix = "Revalidation."; + private const string DurationToFindRevalidations = RevalidationPrefix + "DurationToFindRevalidationsSeconds"; private const string DurationToStartNextRevalidation = RevalidationPrefix + "DurationToStartNextRevalidationSeconds"; private const string PackageRevalidationMarkedAsCompleted = RevalidationPrefix + "PackageRevalidationMarkedAsCompleted"; private const string PackageRevalidationStarted = RevalidationPrefix + "PackageRevalidationStarted"; @@ -26,6 +27,11 @@ public TelemetryService(ITelemetryClient client) _client = client ?? throw new ArgumentNullException(nameof(client)); } + public IDisposable TrackFindNextRevalidations() + { + return _client.TrackDuration(DurationToFindRevalidations); + } + public DurationMetric TrackStartNextRevalidationOperation() { return _client.TrackDuration( diff --git a/src/NuGet.Services.Revalidate/Settings/dev.json b/src/NuGet.Services.Revalidate/Settings/dev.json index 12c0278c2..32ac77026 100644 --- a/src/NuGet.Services.Revalidate/Settings/dev.json +++ b/src/NuGet.Services.Revalidate/Settings/dev.json @@ -27,9 +27,8 @@ }, "Queue": { - "MaximumPackageVersions": #{Jobs.nuget.services.revalidate.MaximumPackageVersions}, - "MaximumAttempts": 5, - "SleepBetweenAttempts": "00:00:30" + "MaxBatchSize": #{Jobs.nuget.services.revalidate.MaxBatchSize}, + "MaximumPackageVersions": #{Jobs.nuget.services.revalidate.MaximumPackageVersions} } }, diff --git a/src/NuGet.Services.Revalidate/Settings/int.json b/src/NuGet.Services.Revalidate/Settings/int.json index 14cd63282..f5b779d5a 100644 --- a/src/NuGet.Services.Revalidate/Settings/int.json +++ b/src/NuGet.Services.Revalidate/Settings/int.json @@ -27,9 +27,8 @@ }, "Queue": { - "MaximumPackageVersions": #{Jobs.nuget.services.revalidate.MaximumPackageVersions}, - "MaximumAttempts": 5, - "SleepBetweenAttempts": "00:00:30" + "MaxBatchSize": #{Jobs.nuget.services.revalidate.MaxBatchSize}, + "MaximumPackageVersions": #{Jobs.nuget.services.revalidate.MaximumPackageVersions} } }, diff --git a/src/NuGet.Services.Revalidate/Settings/prod.json b/src/NuGet.Services.Revalidate/Settings/prod.json index 7dfc3e532..df04abfa6 100644 --- a/src/NuGet.Services.Revalidate/Settings/prod.json +++ b/src/NuGet.Services.Revalidate/Settings/prod.json @@ -27,9 +27,8 @@ }, "Queue": { - "MaximumPackageVersions": #{Jobs.nuget.services.revalidate.MaximumPackageVersions}, - "MaximumAttempts": 5, - "SleepBetweenAttempts": "00:00:30" + "MaxBatchSize": #{Jobs.nuget.services.revalidate.MaxBatchSize}, + "MaximumPackageVersions": #{Jobs.nuget.services.revalidate.MaximumPackageVersions} } }, diff --git a/src/StatusAggregator/StatusAggregator.csproj b/src/StatusAggregator/StatusAggregator.csproj index 9918057f3..0fd160d6c 100644 --- a/src/StatusAggregator/StatusAggregator.csproj +++ b/src/StatusAggregator/StatusAggregator.csproj @@ -157,13 +157,13 @@ 1.1.1 - 2.29.0 + 2.33.0 - 2.29.0 + 2.33.0 - 2.29.0 + 2.33.0 9.2.0 diff --git a/src/Validation.ScanAndSign.Core/Validation.ScanAndSign.Core.csproj b/src/Validation.ScanAndSign.Core/Validation.ScanAndSign.Core.csproj index f05d947c9..cb3a8038d 100644 --- a/src/Validation.ScanAndSign.Core/Validation.ScanAndSign.Core.csproj +++ b/src/Validation.ScanAndSign.Core/Validation.ScanAndSign.Core.csproj @@ -64,7 +64,7 @@ all - 2.27.0 + 2.33.0 0.3.0 diff --git a/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationQueueFacts.cs b/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationQueueFacts.cs index bdff6dbc1..73af9b5c7 100644 --- a/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationQueueFacts.cs +++ b/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationQueueFacts.cs @@ -16,7 +16,7 @@ namespace NuGet.Services.Revalidate.Tests.Services { public class RevalidationQueueFacts { - public class TheNextOrNullAsyncMethod : FactsBase + public class TheNextAsyncMethod : FactsBase { [Fact] public async Task SkipsEnqueuedOrCompletedRevalidations() @@ -69,28 +69,36 @@ public async Task SkipsEnqueuedOrCompletedRevalidations() }); // Act - var next = await _target.NextOrNullAsync(); + var nextRevalidations = await _target.NextAsync(); // Assert + var next = Assert.Single(nextRevalidations); Assert.Equal("Package", next.PackageId); Assert.Equal("1.0.0", next.PackageNormalizedVersion); + + _validationContext.Verify(c => c.SaveChangesAsync(), Times.Never); + _telemetryService.Verify(t => t.TrackFindNextRevalidations(), Times.Once); } [Fact] public async Task SkipsRepositorySignedPackages() { // Arrange + _config.MaxBatchSize = 10; + + var repositorySignedPackageRevalidation = new PackageRevalidation + { + Key = 1, + PackageId = "Repository.Signed.Package", + PackageNormalizedVersion = "1.0.0", + Enqueued = null, + Completed = false, + }; + _validationContext.Mock( packageRevalidations: new[] { - new PackageRevalidation - { - Key = 1, - PackageId = "Repository.Signed.Package", - PackageNormalizedVersion = "1.0.0", - Enqueued = null, - Completed = false, - }, + repositorySignedPackageRevalidation, new PackageRevalidation { Key = 2, @@ -121,16 +129,27 @@ public async Task SkipsRepositorySignedPackages() PackageRegistration = new PackageRegistration { Id = "Package" }, NormalizedVersion = "1.0.0", PackageStatusKey = PackageStatus.Available, + }, + new Package + { + PackageRegistration = new PackageRegistration { Id = "Repository.Signed.Package" }, + NormalizedVersion = "1.0.0", + PackageStatusKey = PackageStatus.Available, } }); // Act - var next = await _target.NextOrNullAsync(); + var nextRevalidations = await _target.NextAsync(); // Assert + var next = Assert.Single(nextRevalidations); Assert.Equal("Package", next.PackageId); Assert.Equal("1.0.0", next.PackageNormalizedVersion); + Assert.True(repositorySignedPackageRevalidation.Completed); + + _validationContext.Verify(c => c.SaveChangesAsync(), Times.Once); + _telemetryService.Verify(t => t.TrackFindNextRevalidations(), Times.Once); _telemetryService.Verify(t => t.TrackPackageRevalidationMarkedAsCompleted("Repository.Signed.Package", "1.0.0"), Times.Once); } @@ -206,9 +225,10 @@ public async Task SkipsPackagesWithTooManyVersions(int? maximumPackageVersions, }); // Act - var next = await _target.NextOrNullAsync(); + var nextRevalidations = await _target.NextAsync(); // Assert + var next = Assert.Single(nextRevalidations); if (skipsPackageWithManyVersions) { Assert.Equal("Package", next.PackageId); @@ -223,6 +243,9 @@ public async Task SkipsPackagesWithTooManyVersions(int? maximumPackageVersions, Assert.Equal("Package.With.Many.Versions", next.PackageId); Assert.Equal("1.0.0", next.PackageNormalizedVersion); } + + _validationContext.Verify(c => c.SaveChangesAsync(), Times.Never); + _telemetryService.Verify(t => t.TrackFindNextRevalidations(), Times.Once); } public static IEnumerable SkipsPackagesWithTooManyVersionsData() @@ -253,24 +276,30 @@ public static IEnumerable SkipsPackagesWithTooManyVersionsData() public async Task SkipsDeletedPackages() { // Arrange + _config.MaxBatchSize = 10; + + var softDeletedPackageRevalidation = new PackageRevalidation + { + Key = 1, + PackageId = "Soft.Deleted.Package", + PackageNormalizedVersion = "1.0.0", + Enqueued = null, + Completed = false, + }; + + var hardDeletedPackageRevalidation = new PackageRevalidation + { + Key = 2, + PackageId = "Hard.Deleted.Package", + PackageNormalizedVersion = "1.0.0", + Enqueued = null, + Completed = false, + }; + _validationContext.Mock(packageRevalidations: new[] { - new PackageRevalidation - { - Key = 1, - PackageId = "Soft.Deleted.Package", - PackageNormalizedVersion = "1.0.0", - Enqueued = null, - Completed = false, - }, - new PackageRevalidation - { - Key = 2, - PackageId = "Hard.Deleted.Package", - PackageNormalizedVersion = "1.0.0", - Enqueued = null, - Completed = false, - }, + softDeletedPackageRevalidation, + hardDeletedPackageRevalidation, new PackageRevalidation { Key = 3, @@ -298,28 +327,37 @@ public async Task SkipsDeletedPackages() }); // Act - var next = await _target.NextOrNullAsync(); + var nextRevalidations = await _target.NextAsync(); // Assert + var next = Assert.Single(nextRevalidations); Assert.Equal("Package", next.PackageId); Assert.Equal("1.0.0", next.PackageNormalizedVersion); + Assert.True(softDeletedPackageRevalidation.Completed); + Assert.True(hardDeletedPackageRevalidation.Completed); + + _validationContext.Verify(c => c.SaveChangesAsync(), Times.Once); + + _telemetryService.Verify(t => t.TrackFindNextRevalidations(), Times.Once); _telemetryService.Verify(t => t.TrackPackageRevalidationMarkedAsCompleted("Soft.Deleted.Package", "1.0.0"), Times.Once); _telemetryService.Verify(t => t.TrackPackageRevalidationMarkedAsCompleted("Hard.Deleted.Package", "1.0.0"), Times.Once); } - [Fact] - public async Task IfReachesAttemptsThreshold_ReturnsNull() + [Theory] + [InlineData(1, false)] + [InlineData(2, true)] + public async Task RespectsTheMaxBatchSizeConfiguration(int maxBatchSize, bool includesSecondVersion) { // Arrange - _config.MaximumAttempts = 1; + _config.MaxBatchSize = maxBatchSize; _validationContext.Mock(packageRevalidations: new[] { new PackageRevalidation { Key = 1, - PackageId = "Hard.Deleted.Package", + PackageId = "Package", PackageNormalizedVersion = "1.0.0", Enqueued = null, Completed = false, @@ -328,7 +366,7 @@ public async Task IfReachesAttemptsThreshold_ReturnsNull() { Key = 2, PackageId = "Package", - PackageNormalizedVersion = "1.0.0", + PackageNormalizedVersion = "2.0.0", Enqueued = null, Completed = false, }, @@ -341,16 +379,30 @@ public async Task IfReachesAttemptsThreshold_ReturnsNull() PackageRegistration = new PackageRegistration { Id = "Package" }, NormalizedVersion = "1.0.0", PackageStatusKey = PackageStatus.Available, + }, + new Package + { + PackageRegistration = new PackageRegistration { Id = "Package" }, + NormalizedVersion = "2.0.0", + PackageStatusKey = PackageStatus.Available, } }); // Act - var next = await _target.NextOrNullAsync(); + var nextRevalidations = await _target.NextAsync(); // Assert - Assert.Null(next); + Assert.Equal(includesSecondVersion ? 2 : 1, nextRevalidations.Count); + Assert.Equal("Package", nextRevalidations[0].PackageId); + Assert.Equal("1.0.0", nextRevalidations[0].PackageNormalizedVersion); - _telemetryService.Verify(t => t.TrackPackageRevalidationMarkedAsCompleted("Hard.Deleted.Package", "1.0.0"), Times.Once); + if (includesSecondVersion) + { + Assert.Equal("Package", nextRevalidations[1].PackageId); + Assert.Equal("2.0.0", nextRevalidations[1].PackageNormalizedVersion); + } + + _telemetryService.Verify(t => t.TrackFindNextRevalidations(), Times.Once); } } @@ -371,8 +423,7 @@ public FactsBase() _config = new RevalidationQueueConfiguration { - MaximumAttempts = 5, - SleepBetweenAttempts = TimeSpan.FromSeconds(0) + MaxBatchSize = 1 }; _target = new RevalidationQueue( diff --git a/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationServiceFacts.cs b/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationServiceFacts.cs index 1065a42ea..8839fe1d7 100644 --- a/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationServiceFacts.cs +++ b/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationServiceFacts.cs @@ -46,8 +46,8 @@ public async Task OnUnrecoverableError_ShutsDown() .ReturnsAsync(true); _starter - .Setup(s => s.StartNextRevalidationAsync()) - .ReturnsAsync(RevalidationResult.UnrecoverableError); + .Setup(s => s.StartNextRevalidationsAsync()) + .ReturnsAsync(StartRevalidationResult.UnrecoverableError); // Act await _target.RunAsync(); @@ -56,7 +56,7 @@ public async Task OnUnrecoverableError_ShutsDown() _telemetryService.Verify(t => t.TrackStartNextRevalidationOperation(), Times.Once); _scopeFactory.Verify(f => f.CreateScope(), Times.Once); - Assert.Equal(RevalidationResult.UnrecoverableError, _operation.Properties.Result); + Assert.Equal(StartRevalidationStatus.UnrecoverableError, _operation.Properties.Result); } [Fact] @@ -68,8 +68,8 @@ public async Task OnRetryLater_CallsThrottlerCallback() .ReturnsAsync(true); _starter - .Setup(s => s.StartNextRevalidationAsync()) - .ReturnsAsync(RevalidationResult.RetryLater); + .Setup(s => s.StartNextRevalidationsAsync()) + .ReturnsAsync(StartRevalidationResult.RetryLater); // Act & Assert await _target.RunAsync(); @@ -78,7 +78,7 @@ public async Task OnRetryLater_CallsThrottlerCallback() _scopeFactory.Verify(f => f.CreateScope(), Times.Once); _throttler.Verify(t => t.DelayUntilRevalidationRetryAsync(), Times.Once); - Assert.Equal(RevalidationResult.RetryLater, _operation.Properties.Result); + Assert.Equal(StartRevalidationStatus.RetryLater, _operation.Properties.Result); } [Fact] @@ -90,17 +90,17 @@ public async Task OnRevalidationEnqueued_CallsThrottlerCallback() .ReturnsAsync(true); _starter - .Setup(s => s.StartNextRevalidationAsync()) - .ReturnsAsync(RevalidationResult.RevalidationEnqueued); + .Setup(s => s.StartNextRevalidationsAsync()) + .ReturnsAsync(StartRevalidationResult.RevalidationsEnqueued(123)); // Act & Assert await _target.RunAsync(); _telemetryService.Verify(t => t.TrackStartNextRevalidationOperation(), Times.Once); _scopeFactory.Verify(f => f.CreateScope(), Times.Once); - _throttler.Verify(t => t.DelayUntilNextRevalidationAsync(), Times.Once); + _throttler.Verify(t => t.DelayUntilNextRevalidationAsync(123, It.IsAny()), Times.Once); - Assert.Equal(RevalidationResult.RevalidationEnqueued, _operation.Properties.Result); + Assert.Equal(StartRevalidationStatus.RevalidationsEnqueued, _operation.Properties.Result); } } @@ -179,27 +179,6 @@ protected void Setup( if (initializedThrows) _jobState.Setup(s => s.IsInitializedAsync()).ThrowsAsync(exception); } - - protected void SetupUnrecoverableErrorResult() - { - _starter - .Setup(s => s.StartNextRevalidationAsync()) - .ReturnsAsync(RevalidationResult.UnrecoverableError); - } - - protected void SetupRetryLaterResult() - { - _starter - .Setup(s => s.StartNextRevalidationAsync()) - .ReturnsAsync(RevalidationResult.RetryLater); - } - - protected void SetupRevalidationEnqueuedResult() - { - _starter - .Setup(s => s.StartNextRevalidationAsync()) - .ReturnsAsync(RevalidationResult.RevalidationEnqueued); - } } } } diff --git a/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationStarterFacts.cs b/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationStarterFacts.cs index 0fbb36063..2b580eb56 100644 --- a/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationStarterFacts.cs +++ b/tests/NuGet.Services.Revalidate.Tests/Services/RevalidationStarterFacts.cs @@ -23,13 +23,14 @@ public async Task IfNotSingleton_ReturnsUnrecoverableError() Setup(isSingleton: false); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); _singletonService.Verify(s => s.IsSingletonAsync(), Times.Once); _jobState.Verify(s => s.IncreaseDesiredPackageEventRateAsync(), Times.Never); _validationEnqueuer.Verify(e => e.StartValidationAsync(It.IsAny()), Times.Never); - Assert.Equal(RevalidationResult.UnrecoverableError, result); + Assert.Equal(StartRevalidationStatus.UnrecoverableError, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -39,9 +40,10 @@ public async Task IfSingletonCheckThrows_ReturnsRetryLater() Setup(singletonThrows: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -51,13 +53,14 @@ public async Task IfKillswitchActive_ReturnsRetryLater() Setup(killswitchActive: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); _jobState.Verify(s => s.IsKillswitchActiveAsync(), Times.Once); _jobState.Verify(s => s.IncreaseDesiredPackageEventRateAsync(), Times.Never); _validationEnqueuer.Verify(e => e.StartValidationAsync(It.IsAny()), Times.Never); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -67,9 +70,10 @@ public async Task IfKillswitchThrows_ReturnsRetryLater() Setup(killswitchThrows: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -79,13 +83,14 @@ public async Task IfThrottled_ReturnsRetryLater() Setup(isThrottled: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); _throttler.Verify(s => s.IsThrottledAsync(), Times.Once); _jobState.Verify(s => s.IncreaseDesiredPackageEventRateAsync(), Times.Never); _validationEnqueuer.Verify(e => e.StartValidationAsync(It.IsAny()), Times.Never); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -95,9 +100,10 @@ public async Task IfThrottledThrows_ReturnsRetryLater() Setup(throttledThrows: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -107,13 +113,14 @@ public async Task IfUnhealthy_ReturnsRetryLater() Setup(isHealthy: false); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); _jobState.Verify(s => s.IncreaseDesiredPackageEventRateAsync(), Times.Never); _healthService.Verify(h => h.IsHealthyAsync(), Times.Once); _validationEnqueuer.Verify(e => e.StartValidationAsync(It.IsAny()), Times.Never); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -123,19 +130,20 @@ public async Task IfUnhealthyThrows_ReturnsRetryLater() Setup(healthyThrows: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] public async Task IfRevalidationQueueEmpty_ReturnsRetryLater() { // Arrange - Setup(next: null); + Setup(next: new List()); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); _singletonService.Verify(s => s.IsSingletonAsync(), Times.Once); _jobState.Verify(s => s.IsKillswitchActiveAsync(), Times.Exactly(2)); @@ -146,7 +154,8 @@ public async Task IfRevalidationQueueEmpty_ReturnsRetryLater() _validationEnqueuer.Verify(e => e.StartValidationAsync(It.IsAny()), Times.Never); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] @@ -156,33 +165,32 @@ public async Task IfRevalidationQueueNextThrows_ReturnsRetryLater() Setup(nextThrows: true); // Act & Assert - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); - Assert.Equal(RevalidationResult.RetryLater, result); + Assert.Equal(StartRevalidationStatus.RetryLater, result.Status); + Assert.Equal(0, result.RevalidationsStarted); } [Fact] public async Task StartsNextRevalidation() { // Arrange - Setup(next: _revalidation); + Setup(next: new List { _revalidation1, _revalidation2 }); - var order = 0; - int enqueueStep = 0; - int markStep = 0; + var steps = new List(); _validationEnqueuer .Setup(e => e.StartValidationAsync(It.IsAny())) - .Callback(() => enqueueStep = order++) + .Callback(m => steps.Add($"Enqueue {m.PackageId} {m.PackageNormalizedVersion}")) .Returns(Task.CompletedTask); _packageState - .Setup(s => s.MarkPackageRevalidationAsEnqueuedAsync(It.IsAny())) - .Callback(() => markStep = order++) + .Setup(s => s.MarkPackageRevalidationsAsEnqueuedAsync(It.IsAny>())) + .Callback(() => steps.Add("Mark as enqueued")) .Returns(Task.CompletedTask); // Act - var result = await _target.StartNextRevalidationAsync(); + var result = await _target.StartNextRevalidationsAsync(); // Assert _singletonService.Verify(s => s.IsSingletonAsync(), Times.Once); @@ -194,17 +202,30 @@ public async Task StartsNextRevalidation() _validationEnqueuer.Verify( e => e.StartValidationAsync(It.Is(m => - m.PackageId == _revalidation.PackageId && - m.PackageNormalizedVersion == _revalidation.PackageNormalizedVersion && - m.ValidationTrackingId == _revalidation.ValidationTrackingId.Value)), + m.PackageId == _revalidation1.PackageId && + m.PackageNormalizedVersion == _revalidation1.PackageNormalizedVersion && + m.ValidationTrackingId == _revalidation1.ValidationTrackingId.Value)), Times.Once); - _packageState.Verify(s => s.MarkPackageRevalidationAsEnqueuedAsync(_revalidation), Times.Once); - _telemetryService.Verify(t => t.TrackPackageRevalidationStarted(_revalidation.PackageId, _revalidation.PackageNormalizedVersion)); + _packageState.Verify( + s => s.MarkPackageRevalidationsAsEnqueuedAsync( + It.Is>( + revalidations => revalidations.Count == 2 && + revalidations[0] == _revalidation1 && + revalidations[1] == _revalidation2)), + Times.Once); + + _telemetryService.Verify(t => t.TrackPackageRevalidationStarted(_revalidation1.PackageId, _revalidation1.PackageNormalizedVersion)); + _telemetryService.Verify(t => t.TrackPackageRevalidationStarted(_revalidation2.PackageId, _revalidation2.PackageNormalizedVersion)); - Assert.Equal(RevalidationResult.RevalidationEnqueued, result); - Assert.Equal(2, order); - Assert.True(enqueueStep < markStep); + Assert.Equal(StartRevalidationStatus.RevalidationsEnqueued, result.Status); + Assert.Equal(2, result.RevalidationsStarted); + + // Verify that revalidations were enqueued before the revalidations were marked as completed. + Assert.Equal(3, steps.Count); + Assert.Equal("Enqueue Foo.Bar 1.2.3", steps[0]); + Assert.Equal("Enqueue Toodle.Doo 4.5.6", steps[1]); + Assert.Equal("Mark as enqueued", steps[2]); } } @@ -219,7 +240,8 @@ public class FactsBase protected readonly Mock _validationEnqueuer; protected readonly Mock _telemetryService; - protected readonly PackageRevalidation _revalidation; + protected readonly PackageRevalidation _revalidation1; + protected readonly PackageRevalidation _revalidation2; public RevalidationStarter _target; @@ -242,13 +264,20 @@ public FactsBase() new StartNextRevalidationOperation(), Mock.Of>>())); - _revalidation = new PackageRevalidation + _revalidation1 = new PackageRevalidation { PackageId = "Foo.Bar", PackageNormalizedVersion = "1.2.3", ValidationTrackingId = Guid.NewGuid() }; + _revalidation2 = new PackageRevalidation + { + PackageId = "Toodle.Doo", + PackageNormalizedVersion = "4.5.6", + ValidationTrackingId = Guid.NewGuid() + }; + _target = new RevalidationStarter( _jobState.Object, _packageState.Object, @@ -266,7 +295,7 @@ protected void Setup( bool killswitchActive = false, bool isThrottled = false, bool isHealthy = true, - PackageRevalidation next = null, + IReadOnlyList next = null, bool initializedThrows = false, bool singletonThrows = false, bool killswitchThrows = false, @@ -278,7 +307,7 @@ protected void Setup( _jobState.Setup(s => s.IsKillswitchActiveAsync()).ReturnsAsync(killswitchActive); _throttler.Setup(t => t.IsThrottledAsync()).ReturnsAsync(isThrottled); _healthService.Setup(t => t.IsHealthyAsync()).ReturnsAsync(isHealthy); - _revalidationQueue.Setup(q => q.NextOrNullAsync()).ReturnsAsync(next); + _revalidationQueue.Setup(q => q.NextAsync()).ReturnsAsync(next); var exception = new Exception(); @@ -286,7 +315,7 @@ protected void Setup( if (killswitchThrows) _jobState.Setup(s => s.IsKillswitchActiveAsync()).ThrowsAsync(exception); if (throttledThrows) _throttler.Setup(t => t.IsThrottledAsync()).ThrowsAsync(exception); if (healthyThrows) _healthService.Setup(t => t.IsHealthyAsync()).ThrowsAsync(exception); - if (nextThrows) _revalidationQueue.Setup(q => q.NextOrNullAsync()).ThrowsAsync(exception); + if (nextThrows) _revalidationQueue.Setup(q => q.NextAsync()).ThrowsAsync(exception); } protected void SetupUnrecoverableErrorResult()