Improved Azure Service Bus logging with Azure Functions

Using  Azure Service Bus with Azure Functions is a great option to trigger functions. If the function fails you'll be able to retry your function. If a function fails to execute you can either investigate your logging tool of choice or look at the error provided by the error message in the dead-letter queue. The question is do you get the information you expect and is it enough to understand the error?

Default error information setup

With Azure Service Bus using the latest Azure.Messaging.ServiceBus the types for messages and SDK has changed a bit. This is the version covered in this post.

We start by creating a standard Azure Function with a ServiceBusTrigger. Afterward, ensure the package Microsoft.Azure.WebJobs.Extensions.ServiceBus is upgraded to 5.2.0 (latest as of writing this post). Update the input trigger to be of type ServiceBusReceivedMessage. This is the new type for receiving messages.

The queue and connection values are both set in the configuration file, hence the syntax.

With this setup, we can simply throw an exception to illustrate the default error information of the function execution.

Testing default error handling

Now when the function executes and the exception is thrown, the error messages provided in the exception should show up, but does it? Let's try it.

To test the setup on your local machine requires 3 steps.

1.  Run the function

Simply start the function on your local machine, debug or non-debug

2.  Send a message to the queue

Sending a message to the queue can be done either from the Azure Portal or a tool like Service Bus Explorer. From the Azure Portal and navigate to the Service Bus Namespace where the queue you're using is located. Select the queue and use the Service Bus Explorer (Preview) tool.

Create a message with content-type set to JSON and a UserId property that matches the type we're expecting in the function. Finally, click send

When the message is sent, we should see the function being triggered. By default, the message is retried 10 times.

3. Monitor message handling

If the function was deployed to Azure, we could use look at the execution there. As we're running locally and we also don't want to wait for the information in Azure, we're using the Service Bus Explorer tool.

The tool requires a connection to the ServiceBus namespace. Inside the tool we can see our queues, here we see "blog", the name of the queue used in this example. The second number in the parentheses indicates the number of dead-letter messages. If we select Dead-letter from the menu below, we can investigate the dead-letter queue. Here we can see the message we sent and also some Message Custom Properties, to the right.

DeadLetterReason and DeadLetterErrorDescription contain the error information, but does it provide us with enough information about what caused the error?

MaxDeliveryCountExceeded

Message could not be consumed after 10 delivery attempts

No information about the actual error that caused the non-handling of the message.

Improved Error Information

To improve error handling, we can make use of the additional property AutoCompleteMessages of the ServiceBusTrigger, and an extra input parameter ServiceBusMessageActions.

AutoCompleteMessages is by default true and ensures automatic complete and dead lettering of failed messages. If we set it to false, we can take over the message handling and provide extra information, exactly what we want.

When we hook into the handling of messages, we also need ServiceBusMessageActions to actually complete or dead-letter messages.

With a little rewrite, the improved Azure Function is now handling exceptions and sending failed messages to the dead-letter queue together with an error message. If the message is handled okay, it's just completed. For illustration, we're just using the UserId to decide whether or not the message handling should fail.

If we send a new message with a UserId of 666 what happens?

Again the message handling fails, and we get another dead-letter message. If we inspect the Service Bus Explorer and Peek the dead-letter queue, we see a second message.

This time the DeadletterReason contains the description provided by the exception message, exactly what we wanted 👍

All source code is available on GitHub