public string RenderMessageWithContext(FeedState feedStateItem)
{
switch (ErrorCategory)
{
case ExpectedErrorCategory.Unauthorised401:
return($"Feed attempting poll returned 401 and will be purged: '{feedStateItem.name}'.");
case ExpectedErrorCategory.DuplicateMessageDetected:
return($"Duplicate message detected for '{feedStateItem.name}': {feedStateItem.id}, and will be dropped.");
case ExpectedErrorCategory.InvalidRPDEPage:
return($"Invalid RPDE page received for '{feedStateItem.name}': {feedStateItem.nextUrl}");
case ExpectedErrorCategory.PageFetchError:
return($"Error retrieving page for '{feedStateItem.name}': {feedStateItem.nextUrl}");
case ExpectedErrorCategory.SqlTransientError:
return($"Throttle on PollFeed, retry after {SqlUtils.SqlRetrySecondsRecommendation} seconds.");
case ExpectedErrorCategory.SqlUnexpectedError:
return($"SQL Error {(this.InnerException as SqlException)?.Number} writing page to SQL Server.");
case ExpectedErrorCategory.UnexpectedErrorDuringDatabaseWrite:
return($"Unexpected error writing page to SQL Server.");
case ExpectedErrorCategory.UnexpectedError:
return($"Unexpected error.");
case ExpectedErrorCategory.ForceClearProxyCache:
return($"ClearProxyCache has been set in App Config. Deadlettering all feeds.");
default:
return($"Unexpected error for '{feedStateItem.name}': {feedStateItem.nextUrl}");
}
}
public static async Task <IActionResult> Run(
[HttpTrigger(AuthorizationLevel.Function, "get", "post", Route = null)] HttpRequest req,
ILogger log)
{
log.LogInformation("C# HTTP trigger function processed a request.");
string name = req.Query["name"];
string ServiceBusConnectionString = Environment.GetEnvironmentVariable("ServiceBusConnection");
var queueClients = new List <IMessageReceiver> {
new MessageReceiver(ServiceBusConnectionString, Utils.FEED_STATE_QUEUE_NAME),
new MessageReceiver(ServiceBusConnectionString, Utils.FEED_STATE_QUEUE_NAME + "/$DeadLetterQueue"),
new MessageReceiver(ServiceBusConnectionString, Utils.PURGE_QUEUE_NAME),
new MessageReceiver(ServiceBusConnectionString, Utils.REGISTRATION_QUEUE_NAME)
};
List <MessageStatus> list = new List <MessageStatus>();
foreach (var client in queueClients)
{
List <MessageStatus> lastRetrievedList = null;
do
{
lastRetrievedList = (await client.PeekAsync(100)).Select(m => new MessageStatus
{
queue = client.Path,
feedState = FeedState.DecodeFromMessage(m),
expiration = m.ExpiresAtUtc,
delayedUntil = m.ScheduledEnqueueTimeUtc,
locked = m.SystemProperties.IsLockTokenSet,
lockedUntil = m.SystemProperties.LockedUntilUtc,
retryAttempts = m.SystemProperties.DeliveryCount,
deadLetterSource = m.SystemProperties.DeadLetterSource,
isReceived = m.SystemProperties.IsReceived
}).ToList();
list.AddRange(lastRetrievedList);
} while (lastRetrievedList.Count > 0);
}
return(new JsonResult(list.OrderBy(x => x.feedState.name).ToList(), new JsonSerializerSettings
{
Converters = new List <JsonConverter>()
{
new StringEnumConverter()
},
Formatting = Formatting.Indented
}));
}
public static async Task Run([ServiceBusTrigger(Utils.FEED_STATE_QUEUE_NAME + "/$DeadLetterQueue", Connection = "ServiceBusConnection")] Message message, MessageReceiver messageReceiver, string lockToken,
[ServiceBus(Utils.PURGE_QUEUE_NAME, Connection = "ServiceBusConnection", EntityType = EntityType.Queue)] IAsyncCollector <Message> purgeQueueCollector,
ILogger log)
{
var feedStateItem = FeedState.DecodeFromMessage(message);
log.LogInformation($"DeadLetterQueue Trigger Started: {feedStateItem.name}");
// Dead letter queue from PollFeed simply triggers a purge
feedStateItem.ResetCounters();
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await purgeQueueCollector.AddAsync(feedStateItem.EncodeToMessage(0));
}
log.LogInformation($"DeadLetterQueue Trigger Complete: {feedStateItem.name}");
}
public static async Task <List <FeedState> > GetFeedStateFromQueues(string name = null, bool ignoreRegistrationQueue = false)
{
string ServiceBusConnectionString = Environment.GetEnvironmentVariable("ServiceBusConnection");
var queueClients = new List <IMessageReceiver> {
new MessageReceiver(ServiceBusConnectionString, Utils.FEED_STATE_QUEUE_NAME),
new MessageReceiver(ServiceBusConnectionString, Utils.FEED_STATE_QUEUE_NAME + "/$DeadLetterQueue"),
new MessageReceiver(ServiceBusConnectionString, Utils.PURGE_QUEUE_NAME)
};
if (!ignoreRegistrationQueue)
{
queueClients.Add(
new MessageReceiver(ServiceBusConnectionString, Utils.REGISTRATION_QUEUE_NAME)
);
}
List <FeedState> list = new List <FeedState>();
foreach (var client in queueClients)
{
List <FeedState> lastRetrievedList = null;
do
{
lastRetrievedList = (await client.PeekAsync(100)).Select(m => FeedState.DecodeFromMessage(m)).ToList();
list.AddRange(lastRetrievedList);
} while (lastRetrievedList.Count > 0);
}
if (name == null)
{
return(list);
}
else
{
return(list.Where(fs => fs.name == name).ToList());
}
}
public static async Task Run([ServiceBusTrigger(Utils.REGISTRATION_QUEUE_NAME, Connection = "ServiceBusConnection")] Message message, MessageReceiver messageReceiver, string lockToken,
[ServiceBus(Utils.REGISTRATION_QUEUE_NAME, Connection = "ServiceBusConnection", EntityType = EntityType.Queue)] IAsyncCollector <Message> queueCollector,
[ServiceBus(Utils.FEED_STATE_QUEUE_NAME, Connection = "ServiceBusConnection", EntityType = EntityType.Queue)] IAsyncCollector <Message> feedStateQueueCollector,
ILogger log)
{
var feedStateItem = FeedState.DecodeFromMessage(message);
// Dead letter queue from PollFeed simply triggers a purge
log.LogInformation($"Registration Trigger Started: {feedStateItem.name}");
// Double-check this feed doesn't already exist
var matchingFeedStateList = await Utils.GetFeedStateFromQueues(feedStateItem.name, true);
if (matchingFeedStateList.Count > 0)
{
if (matchingFeedStateList.First().url != feedStateItem.url)
{
log.LogError($"Conflicting feed already registered with same name '{feedStateItem.name}' using different url '{matchingFeedStateList.First().url}', and will be dropped.");
}
else
{
log.LogError($"Conflicting feed already registered with same name '{feedStateItem.name}' using same url '{matchingFeedStateList.First().url}', and will be dropped.");
}
await messageReceiver.CompleteAsync(lockToken);
return;
}
// Attempt to get first page
try
{
var result = await httpClient.GetAsync(feedStateItem.nextUrl);
if (result.StatusCode == HttpStatusCode.Unauthorized)
{
// Remove from queue on 401 (OWS key has changed)
log.LogWarning($"Feed attempting registration returned 401 and will be dropped: '{feedStateItem.name}'.");
DeleteFeedFromDatabase(feedStateItem.name);
await messageReceiver.CompleteAsync(lockToken);
return;
}
else
{
var data = JsonConvert.DeserializeObject <RpdeFeed>(await result.Content.ReadAsStringAsync());
// check for "license" and valid data: "https://creativecommons.org/licenses/by/4.0/"
if (data?.license != Utils.CC_BY_LICENSE)
{
throw new ApplicationException($"Registration error while validating first page - dropping feed. Error retrieving license for '{feedStateItem.url}'.");
}
}
}
catch (Exception ex)
{
feedStateItem.lastError = ex.ToString();
// Retry registration three times over 30 minutes, then fail
if (feedStateItem.registrationRetries > 3)
{
log.LogError($"Registration error while validating first page. Dropping feed. Error retrieving '{feedStateItem.url}'. {ex.ToString()}");
DeleteFeedFromDatabase(feedStateItem.name);
await messageReceiver.CompleteAsync(lockToken);
}
else
{
feedStateItem.registrationRetries++;
feedStateItem.totalErrors++;
log.LogWarning($"Registration error while validating first page. Retrying '{feedStateItem.name}' attempt {feedStateItem.registrationRetries}. Error retrieving '{feedStateItem.url}'. {ex.ToString()}");
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await queueCollector.AddAsync(feedStateItem.EncodeToMessage(30));
}
}
return;
}
// Write the successful registration to the feeds table
using (var db = new Database(SqlUtils.SqlDatabaseConnectionString, DatabaseType.SqlServer2012, SqlClientFactory.Instance))
{
db.Save <Feed>(new Feed
{
source = feedStateItem.name,
url = feedStateItem.url,
datasetUrl = feedStateItem.datasetUrl,
initialFeedState = feedStateItem
});
}
// Restart the feed from the beginning
feedStateItem.nextUrl = feedStateItem.url;
feedStateItem.ResetCounters();
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await feedStateQueueCollector.AddAsync(feedStateItem.EncodeToMessage(0));
}
log.LogInformation($"Registration Trigger Promoting Feed: {feedStateItem.name}");
}
public string RenderMessageWithFullContext(FeedState feedStateItem, string retryContext)
{
return($"{RenderMessageWithContext(feedStateItem)}. {retryContext} {this.InnerException?.ToString()}");
}
public static async Task Run([ServiceBusTrigger(Utils.FEED_STATE_QUEUE_NAME, Connection = "ServiceBusConnection")] Message message, MessageReceiver messageReceiver, string lockToken,
[ServiceBus(Utils.FEED_STATE_QUEUE_NAME, Connection = "ServiceBusConnection", EntityType = EntityType.Queue)] IAsyncCollector <Message> queueCollector,
ILogger log)
{
var feedStateItem = FeedState.DecodeFromMessage(message);
log.LogInformation($"PollQueueHandler queue trigger function processed message: {feedStateItem?.nextUrl}");
// Increment poll requests before anything else
feedStateItem.totalPollRequests++;
feedStateItem.dateModified = DateTime.Now;
SourcePage sourcePage;
try
{
sourcePage = await ExecutePoll(feedStateItem.name, feedStateItem.nextUrl, feedStateItem.lastPageReads == 0, feedStateItem.deletedItemDaysToLive, log);
}
catch (Exception ex)
{
var expectedException = ExpectedPollException.ExpectTheUnexpected(ex);
feedStateItem.retryStategy = new RetryStrategy(expectedException, feedStateItem?.retryStategy);
feedStateItem.totalErrors++;
if (feedStateItem.retryStategy.DeadLetter)
{
log.LogError(expectedException.RenderMessageWithFullContext(feedStateItem, $"DEAD-LETTERING: '{feedStateItem.name}'."));
await messageReceiver.DeadLetterAsync(lockToken);
}
if (feedStateItem.retryStategy.DropImmediately)
{
log.LogWarning(expectedException.RenderMessageWithFullContext(feedStateItem, $"Dropped message for '{feedStateItem.name}'."));
await messageReceiver.CompleteAsync(lockToken);
}
else
{
feedStateItem.lastError = expectedException.RenderMessageWithFullContext(feedStateItem, $"Retrying '{feedStateItem.name}' attempt {feedStateItem.retryStategy.RetryCount} in {feedStateItem.retryStategy.DelaySeconds} seconds.");
log.LogWarning(feedStateItem.lastError);
var retryMsg = feedStateItem.EncodeToMessage(feedStateItem.retryStategy.DelaySeconds);
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await queueCollector.AddAsync(retryMsg);
}
}
return;
}
// Update counters on success
if (sourcePage.IsLastPage)
{
feedStateItem.lastPageReads++;
}
else
{
feedStateItem.lastPageReads = 0;
}
feedStateItem.retryStategy = null;
feedStateItem.lastError = null;
feedStateItem.totalPagesRead++;
feedStateItem.totalItemsRead += sourcePage.Content.items.Count;
feedStateItem.nextUrl = sourcePage.Content.next;
Message newMessage;
// If immediate poll is specified for last page, respect any Expires header provided for throttling
if (sourcePage.IsLastPage)
{
if (sourcePage.LastPageDetails?.Expires != null)
{
newMessage = feedStateItem.EncodeToMessage(sourcePage.LastPageDetails.Expires);
}
else if (sourcePage.LastPageDetails?.MaxAge != null)
{
newMessage = feedStateItem.EncodeToMessage((int)sourcePage.LastPageDetails.MaxAge?.TotalSeconds);
}
else
{
// Default last page polling interval
newMessage = feedStateItem.EncodeToMessage(Utils.DEFAULT_POLL_INTERVAL);
}
}
else
{
// If not last page, get the next page immediately
newMessage = feedStateItem.EncodeToMessage(0);
}
// These two operations should be in a transaction, but to save cost they ordered so that a failure will result in the polling stopping,
// and the ResyncDroppedFeeds timer trigger will hence be required to ensure the system is still robust
// using (var scope = new TransactionScope(TransactionScopeAsyncFlowOption.Enabled))
// {
// await messageReceiver.CompleteAsync(lockToken);
// await queueCollector.AddAsync(newMessage);
// scope.Complete(); // declare the transaction done
// }
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await queueCollector.AddAsync(newMessage);
}
}
public static async Task Run([ServiceBusTrigger(Utils.PURGE_QUEUE_NAME, Connection = "ServiceBusConnection")] Message message, MessageReceiver messageReceiver, string lockToken,
[ServiceBus(Utils.PURGE_QUEUE_NAME, Connection = "ServiceBusConnection", EntityType = EntityType.Queue)] IAsyncCollector <Message> queueCollector,
[ServiceBus(Utils.REGISTRATION_QUEUE_NAME, Connection = "ServiceBusConnection", EntityType = EntityType.Queue)] IAsyncCollector <Message> registrationQueueCollector,
ILogger log)
{
var feedStateItem = FeedState.DecodeFromMessage(message);
log.LogInformation($"Purge Trigger Started: {feedStateItem.name}");
try
{
int itemCount = 0;
var sw = new Stopwatch();
sw.Start();
using (var db = new Database(SqlUtils.SqlDatabaseConnectionString, DatabaseType.SqlServer2012, SqlClientFactory.Instance))
{
itemCount = await db.ExecuteAsync("DELETE_SOURCE @0", feedStateItem.name);
}
sw.Stop();
log.LogWarning($"PURGE TIMER {feedStateItem.name}: Deleted {itemCount} items from source '{feedStateItem.name}' in {sw.ElapsedMilliseconds} ms");
feedStateItem.purgedItems = itemCount;
if (itemCount < 1000)
{
log.LogInformation($"Purge complete for '{feedStateItem.name}'");
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
// Attempt re-registration unless the proxy cache is being cleared
if (Environment.GetEnvironmentVariable("ClearProxyCache")?.ToString() != "true")
{
feedStateItem.ResetCounters();
feedStateItem.totalPurgeCount++;
await registrationQueueCollector.AddAsync(feedStateItem.EncodeToMessage(1));
}
else
{
log.LogWarning($"Purge Successfully Cleaned: {feedStateItem.name}");
}
}
}
else
{
feedStateItem.purgedItems += itemCount;
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await queueCollector.AddAsync(feedStateItem.EncodeToMessage(1));
}
}
}
catch (SqlException ex)
{
log.LogError($"Error during DELETE_SOURCE stored procedure {ex.Number}: " + ex.ToString());
feedStateItem.lastError = ex.ToString();
feedStateItem.purgeRetries++;
TimeSpan timeSpan = new TimeSpan(1, 0, 0);
Random randomTest = new Random();
TimeSpan newSpan = TimeSpan.FromMinutes(randomTest.Next(0, (int)timeSpan.TotalMinutes));
int delaySeconds = (int)newSpan.TotalSeconds;
log.LogWarning($"Unexpected error purging items: Retrying '{feedStateItem.name}' attempt {feedStateItem.purgeRetries} in {delaySeconds} seconds");
// Check lock exists, as close to a transaction as we can get
if (await messageReceiver.RenewLockAsync(lockToken) != null)
{
await messageReceiver.CompleteAsync(lockToken);
await queueCollector.AddAsync(feedStateItem.EncodeToMessage(delaySeconds));
}
}
log.LogInformation($"Purge Trigger Complete: {feedStateItem.name}");
}
