private async Task <TimeSpan?> ComputeLagForQueries(
Instance instance,
string packageId,
string packageVersion,
bool listed,
DateTimeOffset created,
DateTimeOffset lastEdited,
bool deleted,
CancellationToken token)
{
await Task.Yield();
try
{
var resultCount = (long)0;
var retryCount = (long)0;
var isListOperation = false;
var shouldRetry = false;
TimeSpan createdDelay, v3Delay;
DateTimeOffset lastReloadTime;
do
{
var searchResultObject = await _searchClient.GetResultForPackageIdVersion(instance, packageId, packageVersion, token);
resultCount = searchResultObject.TotalHits;
shouldRetry = false;
if (resultCount > 0)
{
if (deleted)
{
shouldRetry = true;
}
else
{
if (retryCount == 0)
{
isListOperation = true;
}
shouldRetry = searchResultObject.Data[0].LastEdited < lastEdited;
}
}
else
{
shouldRetry = !deleted;
}
if (shouldRetry)
{
++retryCount;
_logger.LogInformation("Waiting for {RetryTime} seconds before retrying {PackageId} {PackageVersion} against {SearchBaseUrl}", WaitBetweenPolls.TotalSeconds, packageId, packageVersion, instance.BaseQueryUrl);
await Task.Delay(WaitBetweenPolls);
}
} while (shouldRetry && retryCount < RetryLimit);
if (retryCount < RetryLimit)
{
lastReloadTime = await _searchClient.GetIndexLastReloadTimeAsync(instance, token);
createdDelay = lastReloadTime - (isListOperation ? lastEdited : created);
v3Delay = lastReloadTime - (lastEdited == DateTimeOffset.MinValue ? created : lastEdited);
var timeStamp = (isListOperation ? lastEdited : created);
// We log both of these values here as they will differ if a package went through validation pipline.
_logger.LogInformation("Lag {Timestamp}:{PackageId} {PackageVersion} SearchInstance:{Region}{Instance} Created: {CreatedLag} V3: {V3Lag}", timeStamp, packageId, packageVersion, instance.Region, instance.Index, createdDelay, v3Delay);
_logger.LogInformation("LastReload:{LastReloadTimestamp} LastEdited:{LastEditedTimestamp} Created:{CreatedTimestamp} ", lastReloadTime, lastEdited, created);
if (!isListOperation)
{
_telemetryService.TrackPackageCreationLag(timeStamp, instance, packageId, packageVersion, createdDelay);
}
else
{
_logger.LogInformation("Skipping log of creation lag for {PackageId} {PackageVersion}. This leaf looks like a list/unlist operation.", packageId, packageVersion);
}
_telemetryService.TrackV3Lag(timeStamp, instance, packageId, packageVersion, v3Delay);
return(createdDelay);
}
else
{
_logger.LogInformation("Lag check for {PackageId} {PackageVersion} was abandoned. Retry limit reached.", packageId, packageVersion);
}
}
catch (Exception e)
{
_logger.LogError("Failed to compute lag for {PackageId} {PackageVersion}. {Exception}", packageId, packageVersion, e);
}
return(null);
}
private async Task <TimeSpan> ComputeLagForQueries(
Instance instance,
string packageId,
string packageVersion,
bool listed,
DateTimeOffset created,
DateTimeOffset lastEdited,
bool deleted,
CancellationToken token)
{
await Task.Yield();
var query = instance.BaseQueryUrl + String.Format(SearchQueryTemplate, packageId, packageVersion);
try
{
var resultCount = (long)0;
var retryCount = (long)0;
var isListOperation = false;
var shouldRetry = false;
TimeSpan createdDelay, v3Delay;
DateTimeOffset lastReloadTime;
_logger.LogInformation("Queueing {Query}", query);
do
{
using (var response = await _client.GetAsync(
query,
HttpCompletionOption.ResponseContentRead,
token))
{
var content = response.Content;
var searchResultRaw = await content.ReadAsStringAsync();
var searchResultObject = JsonConvert.DeserializeObject <SearchResultResponse>(searchResultRaw);
resultCount = searchResultObject.TotalHits;
shouldRetry = false;
if (resultCount > 0)
{
if (deleted)
{
shouldRetry = true;
}
else
{
if (retryCount == 0)
{
isListOperation = true;
}
shouldRetry = searchResultObject.Data[0].LastEdited < lastEdited;
}
}
}
if (shouldRetry)
{
++retryCount;
_logger.LogInformation("Waiting for {RetryTime} seconds before retrying {PackageId} {PackageVersion} Query:{Query}", WaitBetweenPolls.TotalSeconds, packageId, packageVersion, query);
await Task.Delay(WaitBetweenPolls);
}
} while (shouldRetry && retryCount < MAX_RETRY_COUNT);
if (retryCount < MAX_RETRY_COUNT)
{
using (var diagResponse = await _client.GetAsync(
instance.DiagUrl,
HttpCompletionOption.ResponseContentRead,
token))
{
var diagContent = diagResponse.Content;
var searchDiagResultRaw = await diagContent.ReadAsStringAsync();
var searchDiagResultObject = JsonConvert.DeserializeObject <SearchDiagnosticResponse>(searchDiagResultRaw);
lastReloadTime = searchDiagResultObject.LastIndexReloadTime;
}
createdDelay = lastReloadTime - (isListOperation ? lastEdited : created);
v3Delay = lastReloadTime - (lastEdited == DateTimeOffset.MinValue ? created : lastEdited);
var timeStamp = (isListOperation ? lastEdited : created);
// We log both of these values here as they will differ if a package went through validation pipline.
_logger.LogInformation("{Timestamp}:{PackageId} {PackageVersion} Query: {Query} Created: {CreatedLag} V3: {V3Lag}", timeStamp, packageId, packageVersion, query, createdDelay, v3Delay);
_telemetryService.TrackPackageCreationLag(timeStamp, instance, packageId, packageVersion, createdDelay);
_telemetryService.TrackV3Lag(timeStamp, instance, packageId, packageVersion, v3Delay);
return(createdDelay);
}
}
catch (Exception e)
{
_logger.LogError("Failed to compute lag for {PackageId} {PackageVersion} with query: {Query}. {Exception}", packageId, packageVersion, query, e);
}
return(new TimeSpan(0));
}
