RMD
RMD

Reputation: 3253

Configure NServiceBus to Log Exceptions that are causing message retries

I'm using NServiceBus 4.6 and Serilog. I've configured NServiceBus to use Serilog via:

global::NServiceBus.SetLoggingLibrary.Custom(new SeriLoggerFactory());

The factory itself is very simple as well:

public class SeriLoggerFactory : ILoggerFactory
{
    public ILog GetLogger(Type type)
    {
        return new SeriLoggerAdapter(Log.ForContext(type));
    }

    public ILog GetLogger(string name)
    {
        var contextLogger = Log.ForContext("SourceContext", name);
        return new SeriLoggerAdapter(contextLogger);
    }
}

I'm definitely getting log entries related to NServiceBus, but one thing that's missing is the exception details when a message is processed but an exception is thrown. I can see the exception information in the NServiceBus message headers (either directly by viewing the message in the error queue, or via Service Insight), but the message that is logged by NServiceBus is missing most relevant information:

Message with '0d255d19-85f9-4915-a27c-a41000da12ed' id has failed FLR and will be handed over to SLR for retry attempt 1

or

SLR has failed to resolve the issue with message 0d255d19-85f9-4915-a27c-a41000da12ed and will be forwarded to the error queue at MYERRORQUEUE

Not having any details about the root exception makes debugging a bit difficult. It requires the developer go open up Service Insight, or open up a tool to view the message in the queue itself. Both are cumbersome, and both lack any extensiblity.

For instance, Serilog allows you to create ILogEventEnricher classes that can log special details about the exception in question - stuff that's not logged by a simple .ToString on the exception. Without NServiceBus actually logging my exceptions, I have no way of extracting these details.

What am I missing here?

Upvotes: 2

Views: 2287

Answers (1)

sverrehundeide
sverrehundeide

Reputation: 162

NServiceBus has a class named NServiceBus.Faults.ErrorsNotifications which contains the following observables:

  • MessageSentToErrorQueue
  • MessageHasFailedAFirstLevelRetryAttempt
  • MessageHasBeenSentToSecondLevelRetries

You can subscribe to these observables when the endpoint starts, like in the following example which logs an error messeages are sent to first level retry:

public class GlobalErrorHandler : IWantToRunWhenBusStartsAndStops
{
    private readonly ILogger _logger;
    private readonly BusNotifications _busNotifications;
    readonly List<IDisposable> _notificationSubscriptions = new List<IDisposable>();

    public GlobalErrorHandler(ILogger logger, BusNotifications busNotifications)
    {
        _logger = logger;
        _busNotifications = busNotifications;
    }

    public void Start()
    {
        _notificationSubscriptions.Add(_busNotifications.Errors.MessageHasFailedAFirstLevelRetryAttempt.Subscribe(LogWhenMessageSentToFirstLevelRetry));
    }

    public void Stop()
    {
        foreach (var subscription in _notificationSubscriptions)
        {
            subscription.Dispose();
        }
    }

    private void LogWhenMessageSentToFirstLevelRetry(FirstLevelRetry message)
    {
        var properties = new
        {
            MessageType = message.Headers["NServiceBus.EnclosedMessageTypes"],
            MessageId = message.Headers["NServiceBus.MessageId"],
            OriginatingMachine = message.Headers["NServiceBus.OriginatingMachine"],
            OriginatingEndpoint = message.Headers["NServiceBus.OriginatingEndpoint"],
            ExceptionType = message.Headers["NServiceBus.ExceptionInfo.ExceptionType"],
            ExceptionMessage = message.Headers["NServiceBus.ExceptionInfo.Message"],
            ExceptionSource = message.Headers["NServiceBus.ExceptionInfo.Source"],
            TimeSent = message.Headers["NServiceBus.TimeSent"]
        };

        _logger.Error("Message sent to first level retry. " + properties, message.Exception);
    }
}

The observable is implemented by using Reactive Extensions, so you will have to install the NuGet package Rx-Core for this to work.

Upvotes: 1

Related Questions