private async Task Dispatch(NimbusMessage message)
{
DispatchLoggingContext.NimbusMessage = message;
// Early exit: have we pre-fetched this message and had our lock already expire? If so, just
// bail - it will already have been picked up by someone else.
var now = _clock.UtcNow;
if (message.ExpiresAfter <= now)
{
_logger.Warn(
"Message {MessageId} appears to have already expired (expires after {ExpiresAfter} and it is now {Now}) so we're not dispatching it. Watch out for clock drift between your hosts!",
message.MessageId,
message.ExpiresAfter,
now);
await PostToDeadLetterOffice(message);
return;
}
try
{
try
{
_logger.Debug("Dispatching message {MessageId}", message.MessageId);
message.RecordDeliveryAttempt(now);
using (_dispatchContextManager.StartNewDispatchContext(new SubsequentDispatchContext(message)))
{
await _messageDispatcher.Dispatch(message);
}
_logger.Debug("Dispatched message {MessageId}", message.MessageId);
return;
}
catch (Exception exc)
{
_logger.Warn(exc, "Dispatch failed for message {MessageId}", message.MessageId);
}
var numDeliveryAttempts = message.DeliveryAttempts.Count();
if (numDeliveryAttempts >= _maxDeliveryAttempts)
{
_logger.Error("Too many delivery attempts ({DeliveryAttempts}) for message {MessageId}.", numDeliveryAttempts, message.MessageId);
await PostToDeadLetterOffice(message);
}
else
{
try
{
var nextDeliveryTime = _deliveryRetryStrategy.CalculateNextRetryTime(message);
_logger.Debug("Re-enqueuing message {MessageId} for attempt {DeliveryAttempts} at delivery at {DeliveryTime}",
message.MessageId,
numDeliveryAttempts + 1,
nextDeliveryTime);
await _delayedDeliveryService.DeliverAfter(message, nextDeliveryTime);
}
catch (Exception exc)
{
_logger.Error(exc, "Failed to re-enqueue message {MessageId} for re-delivery.", message.MessageId);
}
}
}
catch (Exception exc)
{
_logger.Error(exc, "Unhandled exception in message pump");
}
}
private async Task Dispatch(BrokeredMessage message)
{
// Early exit: have we pre-fetched this message and had our lock already expire? If so, just
// bail - it will already have been picked up by someone else.
if (message.LockedUntilUtc <= _clock.UtcNow)
{
_logger.Debug("Lock for message {MessageId} appears to have already expired so we're not dispatching it. Watch out for clock drift between your service bus server and {MachineName}!", message.MessageId, Environment.MachineName);
return;
}
try
{
Exception exception = null;
try
{
LogInfo("Dispatching", message);
using (_dispatchContextManager.StartNewDispatchContext(new SubsequentDispatchContext(message)))
{
await _taskFactory.StartNew(() => _messageDispatcher.Dispatch(message), TaskContext.Dispatch).Unwrap();
}
LogDebug("Dispatched", message);
LogDebug("Completing", message);
message.Properties[MessagePropertyKeys.DispatchComplete] = true;
await _taskFactory.StartNew(() => message.CompleteAsync(), TaskContext.CompleteOrAbandon).Unwrap();
LogInfo("Completed", message);
return;
}
catch (Exception exc)
{
if (exc is MessageLockLostException || (exc.InnerException is MessageLockLostException))
{
_logger.Error(exc,
"Message completion failed for {Type} from {QueuePath} [MessageId:{MessageId}, CorrelationId:{CorrelationId}]",
message.SafelyGetBodyTypeNameOrDefault(),
message.ReplyTo,
message.MessageId,
message.CorrelationId);
return;
}
_logger.Error(exc,
"Message dispatch failed for {Type} from {QueuePath} [MessageId:{MessageId}, CorrelationId:{CorrelationId}]",
message.SafelyGetBodyTypeNameOrDefault(),
message.ReplyTo,
message.MessageId,
message.CorrelationId);
exception = exc;
}
try
{
LogDebug("Abandoning", message);
await message.AbandonAsync(exception.ExceptionDetailsAsProperties(_clock.UtcNow));
LogDebug("Abandoned", message);
}
catch (Exception exc)
{
_logger.Error(exc,
"Could not call Abandon() on message {Type} from {QueuePath} [MessageId:{MessageId}, CorrelationId:{CorrelationId}].",
message.SafelyGetBodyTypeNameOrDefault(),
message.MessageId,
message.CorrelationId,
message.ReplyTo);
}
}
catch (Exception exc)
{
_logger.Error(exc, "Unhandled exception in message pump");
}
}
