public async Task <ValidationSetProcessorResult> ProcessValidationsAsync(PackageValidationSet validationSet)
{
_logger.LogInformation("Starting processing validation request for {PackageId} {PackageVersion}, validation set {ValidationSetId}",
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId);
var processorStats = new ValidationSetProcessorResult();
int loopLimit = MaxProcessAttempts;
await ProcessIncompleteValidations(validationSet, processorStats);
bool hadSucceededValidations = false;
do
{
// we will try to start more validations in case previous validation start attempts
// result in Succeeded validation immediately (i.e. the validation was synchronous).
// If no validation start attempts resulted in succeeded validation (ProcessNotStartedValidations
// returns false) we move on and will check on progress later.
// loopLimit is there to prevent looping here infinitely if there are any bugs that
// cause ProcessNotStartedValidations to always return true.
hadSucceededValidations = await ProcessNotStartedValidations(validationSet, processorStats);
} while (hadSucceededValidations && loopLimit-- > 0);
if (loopLimit <= 0)
{
_logger.LogWarning("Too many processing attempts ({NumAttempts}) for {PackageId} {PackageVersion}, validation set {ValidationSetId}",
MaxProcessAttempts,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId);
}
return(processorStats);
}
private void UpdateStatsForValidationSuccess(ValidationSetProcessorResult processorStats, ValidationConfigurationItem validationConfiguration)
{
processorStats.AnyValidationSucceeded = true;
if (validationConfiguration.FailureBehavior == ValidationFailureBehavior.MustSucceed)
{
processorStats.AnyRequiredValidationSucceeded = true;
}
}
public async Task ProcessValidationOutcomeAsync(PackageValidationSet validationSet, IValidatingEntity <T> validatingEntity, ValidationSetProcessorResult currentCallStats)
{
var failedValidations = GetFailedValidations(validationSet);
if (failedValidations.Any())
{
_logger.LogWarning("Some validations failed for package {PackageId} {PackageVersion}, validation set {ValidationSetId}: {FailedValidations}",
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
failedValidations.Select(x => x.Type).ToList());
// The only way we can move to the failed validation state is if the package is currently in the
// validating state. This has a beneficial side effect of only sending a failed validation email to the
// customer when the package first moves to the failed validation state. If an admin comes along and
// revalidates the package and the package fails validation again, we don't want another email going
// out since that would be noisy for the customer.
if (validatingEntity.Status == PackageStatus.Validating)
{
await _packageStateProcessor.SetStatusAsync(validatingEntity, validationSet, PackageStatus.FailedValidation);
await MarkValidationSetAsCompletedAsync(validationSet);
await _messageService.SendValidationFailedMessageAsync(validatingEntity.EntityRecord, validationSet);
}
else
{
// The case when validation fails while PackageStatus not validating is the case of
// manual revalidation. In this case we don't want to take package down automatically
// and let the person who requested revalidation to decide how to proceed. Ops will be
// alerted by failed validation monitoring.
_logger.LogInformation("Package {PackageId} {PackageVersion} was {PackageStatus} when validation set {ValidationSetId} failed. Will not mark it as failed.",
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validatingEntity.Status,
validationSet.ValidationTrackingId);
await MarkValidationSetAsCompletedAsync(validationSet);
}
TrackValidationSetCompletion(validationSet, isSuccess: false);
await _packageFileService.DeletePackageForValidationSetAsync(validationSet);
}
else if (AllRequiredValidationsSucceeded(validationSet))
{
_logger.LogInformation("All validations are complete for the package {PackageId} {PackageVersion}, validation set {ValidationSetId}",
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId);
var fromStatus = validatingEntity.Status;
// Always set the package status to available so that processors can have a chance to fix packages
// that are already available. Processors should no-op when their work is already done, so the
// modification of an already available package should be rare. The most common case for this is if
// the processor has never been run on a package that was published before the processor was
// implemented. In this case, the processor has to play catch-up.
await _packageStateProcessor.SetStatusAsync(validatingEntity, validationSet, PackageStatus.Available);
var areOptionalValidationsRunning = AreOptionalValidationsRunning(validationSet);
if (!areOptionalValidationsRunning)
{
await MarkValidationSetAsCompletedAsync(validationSet);
}
// Only send the email when first transitioning into the Available state.
if (fromStatus != PackageStatus.Available)
{
await _messageService.SendPublishedMessageAsync(validatingEntity.EntityRecord);
}
if (currentCallStats.AnyRequiredValidationSucceeded)
{
TrackValidationSetCompletion(validationSet, isSuccess: true);
}
if (areOptionalValidationsRunning)
{
await ScheduleCheckIfNotTimedOut(validationSet, validatingEntity, tooLongNotificationAllowed : false);
}
// TODO: implement delayed cleanup that would allow internal services
// to access original packages for some time after package become available:
// https://github.com/NuGet/Engineering/issues/2506
}
else
{
await ScheduleCheckIfNotTimedOut(validationSet, validatingEntity, tooLongNotificationAllowed : true);
}
}
private async Task ProcessIncompleteValidations(PackageValidationSet validationSet, ValidationSetProcessorResult processorStats)
{
foreach (var packageValidation in validationSet.PackageValidations.Where(v => v.ValidationStatus == ValidationStatus.Incomplete))
{
using (_logger.BeginScope("Incomplete {ValidationType} Key {ValidationId}", packageValidation.Type, packageValidation.Key))
{
_logger.LogInformation("Processing incomplete validation {ValidationType} for {PackageId} {PackageVersion}, validation set {ValidationSetId}, {ValidationId}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
packageValidation.Key);
var validationConfiguration = GetValidationConfiguration(packageValidation.Type);
if (validationConfiguration == null)
{
await OnUnknownValidation(packageValidation);
continue;
}
var validator = _validatorProvider.GetValidator(packageValidation.Type);
var validationRequest = await CreateValidationRequest(packageValidation.PackageValidationSet, packageValidation);
var validationResult = await validator.GetResultAsync(validationRequest);
if (validationResult.Status != ValidationStatus.Incomplete)
{
_logger.LogInformation(
"New status for validation {ValidationType} for {PackageId} {PackageVersion} is " +
"{ValidationStatus}, validation set {ValidationSetId}, {ValidationId}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationResult.Status,
validationSet.ValidationTrackingId,
packageValidation.Key);
}
else
{
_logger.LogDebug(
"Validation {ValidationType} for {PackageId} {PackageVersion} is already " +
"{ValidationStatus}, validation set {ValidationSetId}, {ValidationId}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationResult.Status,
validationSet.ValidationTrackingId,
packageValidation.Key);
}
switch (validationResult.Status)
{
case ValidationStatus.Incomplete:
break;
case ValidationStatus.Failed:
await _validationStorageService.UpdateValidationStatusAsync(packageValidation, validationResult);
await validator.CleanUpAsync(validationRequest);
break;
case ValidationStatus.Succeeded:
await _validationStorageService.UpdateValidationStatusAsync(packageValidation, validationResult);
await validator.CleanUpAsync(validationRequest);
UpdateStatsForValidationSuccess(processorStats, validationConfiguration);
break;
default:
throw new InvalidOperationException($"Unexpected validation state: " +
$"DB: {ValidationStatus.Incomplete} ({(int)ValidationStatus.Incomplete}), " +
$"Actual: {validationResult.Status} {(int)validationResult.Status}");
}
}
}
}
private async Task <bool> ProcessNotStartedValidations(PackageValidationSet validationSet, ValidationSetProcessorResult processorStats)
{
bool tryMoreValidations = false;
foreach (var packageValidation in validationSet.PackageValidations.Where(v => v.ValidationStatus == ValidationStatus.NotStarted))
{
using (_logger.BeginScope("Not started {ValidationType} Key {ValidationId}", packageValidation.Type, packageValidation.Key))
{
_logger.LogInformation("Processing not started validation {ValidationType} for {PackageId} {PackageVersion}, validation set {ValidationSetId}, {ValidationId}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
packageValidation.Key);
var validationConfiguration = GetValidationConfiguration(packageValidation.Type);
if (validationConfiguration == null)
{
await OnUnknownValidation(packageValidation);
continue;
}
if (!validationConfiguration.ShouldStart)
{
continue;
}
bool prerequisitesAreMet = ArePrerequisitesMet(packageValidation, validationSet);
if (!prerequisitesAreMet)
{
_logger.LogInformation("Prerequisites are not met for validation {ValidationType} for {PackageId} {PackageVersion}, validation set {ValidationSetId}, {ValidationId}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
packageValidation.Key);
continue;
}
var validator = _validatorProvider.GetValidator(packageValidation.Type);
var validationRequest = await CreateValidationRequest(packageValidation.PackageValidationSet, packageValidation);
var validationResult = await validator.GetResultAsync(validationRequest);
if (validationResult.Status == ValidationStatus.NotStarted)
{
_logger.LogInformation("Requesting validation {ValidationType} for {PackageId} {PackageVersion}, validation set {ValidationSetId}, {ValidationId}, {NupkgUrl}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
packageValidation.Key,
validationRequest.NupkgUrl);
try
{
validationResult = await validator.StartAsync(validationRequest);
}
catch (Exception e) when(validationConfiguration.FailureBehavior != ValidationFailureBehavior.MustSucceed)
{
// ignore exceptions for optional validators
_logger.LogWarning(0, e, "Got exception while running optional validation {ValidationType} for " +
"{PackageId} {PackageVersion}, validation set {ValidationSetId}, {ValidationId}, {NupkgUrl}",
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
packageValidation.Key,
validationRequest.NupkgUrl);
}
_logger.LogInformation("Got validationStatus = {ValidationStatus} for validation {ValidationType} for {PackageId} {PackageVersion}, validation set {ValidationSetId}, {ValidationId}",
validationResult.Status,
packageValidation.Type,
validationSet.PackageId,
validationSet.PackageNormalizedVersion,
validationSet.ValidationTrackingId,
packageValidation.Key);
}
if (validationResult.Status == ValidationStatus.NotStarted)
{
_logger.LogWarning("Unexpected NotStarted state after start attempt for validation {ValidationName}, package: {PackageId} {PackageVersion}",
packageValidation.Type,
packageValidation.PackageValidationSet.PackageId,
packageValidation.PackageValidationSet.PackageNormalizedVersion);
}
else
{
await _validationStorageService.MarkValidationStartedAsync(packageValidation, validationResult);
if (validationResult.Status == ValidationStatus.Succeeded ||
validationResult.Status == ValidationStatus.Failed)
{
await validator.CleanUpAsync(validationRequest);
}
_telemetryService.TrackValidatorStarted(validationSet.PackageId, validationSet.PackageNormalizedVersion, validationSet.ValidationTrackingId, packageValidation.Type);
if (validationResult.Status == ValidationStatus.Succeeded)
{
UpdateStatsForValidationSuccess(processorStats, validationConfiguration);
tryMoreValidations = true;
}
}
}
}
return(tryMoreValidations);
}
