0

I'm running an NServiceBus endpoint on an Azure Workerrole. I send all diagnostics to table storage at the moment. I was getting messages in my DLQ, and I couldn't figure out why I wasn't getting any exceptions logged in my table storage.

It turns out that NSB logs the exceptions as INFO, which is why I couldn't easily spot them in between all the actual verbose logging.

In my case, a command handler's dependencies couldn't be resolved so Autofac throws an exception. I totally get why the exception is thrown, I just don't understand why they're logged as INFO. The message ends up in my DLQ, and I only have a INFO-trace to understand why.

Is there a reason why exceptions are handled this way in NSB?

Sean Feldman
  • 23,443
  • 7
  • 55
  • 80
Laila
  • 499
  • 1
  • 5
  • 7
  • When you're saying "It turns out that NSB logs the exceptions as INFO", do you mean handler failing to load exceptions or literally all exceptions? If handler is loaded and exception is thrown, it will be logged as an error. Could you please clarify? – Sean Feldman Mar 30 '16 at 22:13
  • I mean that the handler failing to load shows up as an INFO in the log: 2016-03-31 08:32:45.910 INFO NServiceBus.Unicast.Transport.TransportReceiver Failed to process message Autofac.Core.DependencyResolutionException: None of the constructors found with 'Autofac.Core.Activators.Reflection.DefaultConstructorFinder' on type 'CommandHandler' can be invoked with the available services and parameters I would expect this to be logged as an error, instead of an INFO. – Laila Mar 31 '16 at 08:33

1 Answers1

2

NServiceBus is not logging container issue as an error because it's happening during an attempt to process a message. First Level Retry and Second Level Retry will be attempted. When SLR is executed, it will log a WARN about the retry. Ultimately, a message will fail processing and an ERROR message will be logged. NSB and Autofac sample can be used to reproduce this.

When endpoint is running with a scaled out role and MadDeliveryCount is not big enough to accommodate all the role instances and retry count that each instance would hold, this will result in DeliveryCount reaching it's max while NServiceBus endpoint instance still thinks it has attempts before sending message to an error queue and logging an error. Similar to the question here I'd recommend to increase MaxDeliveryCount.

There is an open NServiceBus issue to have a native support for SLR counter. You can add your voice to the issue. The next version of NServiceBus (V6) will be logging message id along with the exception so that you at least could correlate between message in DLQ and log file.

Community
  • 1
  • 1
Sean Feldman
  • 23,443
  • 7
  • 55
  • 80