NSB Azure Function "Transaction in doubt" random errors

jens · July 1, 2022, 6:06am

We have setup an endpoint on Azure Functions (NServiceBus.AzureFunctions.InProcess.ServiceBus 3.0.0) that’s currently not subscribing to any events at all, it just sits there idleing but are ready to start receive messages when we decide to. The only thing that’s activated is a timer trigger that sends a command to the endpoint itself every 10 minutes just to test that everything is operational.

However, we see random The transaction is in doubt. The operation was canceled. exceptions that occurs a couple of times a day and we can’t figure out why. Some days it never happens at all and some days it happens 3-4 times. Given the timer trigger is the only “producer” of messages the endpoint gets only 6 messages an hour, 144 per day, it’s a bit alarming to see that many exceptions.

We have another very well used endpoint that we haven’t upgraded to 3.0.0 yet, still using NServiceBus.AzureFunctions.InProcess.ServiceBus 2.1.0. This endpoint uses the same Azure Service Bus namespace and we never see this exception there.

Before going live with the new endpoint, or upgrading the older ones to 3.0.0 we really like to figure out why this exception occurs.

Both functions are running on: .net6 and Microsoft.NET.Sdk.Functions 4.0.1, the only difference is that the new endpoint uses: Microsoft.Azure.WebJobs.Extensions.ServiceBus 5.2.0 while the older one uses 4.3.0.

Some of the exceptions

From top to bottom in the image above:

Immediate Retry is going to retry message '186f8091-ff76-481b-92f3-aec400de792b' because of an exception:

System.Transactions.TransactionInDoubtException:
   at System.Transactions.TransactionStateInDoubt.EndCommit (System.Transactions.Local, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51)
   at System.Transactions.CommittableTransaction.Commit (System.Transactions.Local, Version=6.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51)
   at NServiceBus.InProcessFunctionEndpoint+<ProcessAtomic>d__14.MoveNext (NServiceBus.AzureFunctions.InProcess.ServiceBus, Version=3.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c: /_/src/NServiceBus.AzureFunctions.InProcess.ServiceBus/InProcessFunctionEndpoint.cs:169)
Inner exception Azure.Messaging.ServiceBus.ServiceBusException handled at System.Transactions.TransactionStateInDoubt.EndCommit:

The next three in rapid succession:

Exception while executing function: <function name>. The lock supplied is invalid. Either the lock expired, or the message has already been removed from the queue, or was received by a different receiver instance. (MessageLockLost)

Microsoft.Azure.WebJobs.Host.FunctionInvocationException:
   at Microsoft.Azure.WebJobs.ServiceBus.MessageProcessor.CompleteProcessingMessageAsync (Microsoft.Azure.WebJobs.Extensions.ServiceBus, Version=5.2.0.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at Microsoft.Azure.WebJobs.ServiceBus.Listeners.ServiceBusListener+<ProcessMessageAsync>d__26.MoveNext (Microsoft.Azure.WebJobs.Extensions.ServiceBus, Version=5.2.0.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusProcessor+<OnProcessMessageAsync>d__104.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ReceiverManager+<OnMessageHandler>d__16.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ReceiverManager+<ProcessOneMessage>d__15.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
Inner exception Azure.Messaging.ServiceBus.ServiceBusException handled at Microsoft.Azure.WebJobs.ServiceBus.MessageProcessor.CompleteProcessingMessageAsync:
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.ThrowLockLostException (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver+<DisposeMessageAsync>d__42.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver+<>c+<<AbandonAsync>b__46_0>d.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy+<>c__20`1+<<RunOperation>b__20_0>d.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Threading.Tasks.ValueTask`1.get_Result (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.ConfiguredValueTaskAwaitable`1+ConfiguredValueTaskAwaiter.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy+<RunOperation>d__21`2.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy+<RunOperation>d__21`2.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy+<RunOperation>d__20`1.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver+<AbandonAsync>d__46.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusReceiver+<AbandonMessageAsync>d__49.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ServiceBusReceiver+<AbandonMessageAsync>d__48.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Azure.Messaging.ServiceBus.ProcessMessageEventArgs+<AbandonMessageAsync>d__8.MoveNext (Azure.Messaging.ServiceBus, Version=7.5.1.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.ServiceBus.ServiceBusMessageActions+<AbandonMessageAsync>d__10.MoveNext (Microsoft.Azure.WebJobs.Extensions.ServiceBus, Version=5.2.0.0, Culture=neutral, PublicKeyToken=92742159e12e44c8)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at NServiceBus.InProcessFunctionEndpoint+<ProcessAtomic>d__14.MoveNext (NServiceBus.AzureFunctions.InProcess.ServiceBus, Version=3.0.0.0, Culture=neutral, PublicKeyToken=9fc386479f8a226c: /_/src/NServiceBus.AzureFunctions.InProcess.ServiceBus/InProcessFunctionEndpoint.cs:193)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.VoidTaskMethodInvoker`2+<InvokeAsync>d__2.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.34.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\VoidTaskMethodInvoker.cs:20)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2+<InvokeAsync>d__10.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.34.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionInvoker.cs:52)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<InvokeWithTimeoutAsync>d__33.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.34.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:581)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<ExecuteWithWatchersAsync>d__32.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.34.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:527)
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult (System.Private.CoreLib, Version=6.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e)
   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor+<ExecuteWithLoggingAsync>d__26.MoveNext (Microsoft.Azure.WebJobs.Host, Version=3.0.34.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35: C:\projects\azure-webjobs-sdk-rqm4t\src\Microsoft.Azure.WebJobs.Host\Executors\FunctionExecutor.cs:306)

We understand what it means by that the “lock supplied is invalid” etc, but we can’t figure out why it’s happening.

Our endpoint trigger function (we don’t use the automatically generated one but the actual function should look the same):

[FunctionName(EndpointName)]
public Task Run(
    [ServiceBusTrigger(
        queueName: EndpointName,
        Connection = ConnectionName,
        AutoCompleteMessages = false)]
    ServiceBusReceivedMessage message,
    ServiceBusClient client,
    ServiceBusMessageActions messageActions,
    ILogger logger,
    ExecutionContext executionContext)
{
    return _endpoint.ProcessAtomic(message, executionContext, client, messageActions, logger);
}

The timer trigger that produces a message every 10 minutes:

[FunctionName("PingTimer")]
public Task RunAsync(
    [TimerTrigger("0 */10 * * * *")] TimerInfo myTimer, 
    ILogger log,
    ExecutionContext executionContext)
{
    var sendOptions = new SendOptions();
    sendOptions.RouteToThisEndpoint();

    return _functionEndpoint.Send(new Ping(), sendOptions, executionContext);
}

Our Azure Function host.json:

"extensions": {
    "ServiceBus": {
        "EnableCrossEntityTransactions": true
    }
},

I can’t reproduce this “locally” (with a personal Azure Service Bus namespace, but running the function locally).

Any ideas to help us figure out why this is happening? We don’t like random exceptions

//J

danielmarbach · July 6, 2022, 6:16am

Hi Jens,

Which version of Azure.Messaging.ServiceBus do you get as a transitive dependency? I have a hunch it is related to a bug in the library there.

Could you do the following:

Upgrade to Microsoft.Azure.WebJobs.Extensions.ServiceBus 5.5.1

Test again. This should bring in Azure.Messaging.ServiceBus 7.8.1 which also includes fixes around the connection/link handling for cross entity transactions

Don’t close entire AMQP session when closing individual AMQP links when EnableCrossEntityTransactions is set to true , since with this configuration, all links will share the same session.

and

Fixed issue that could result in the message lock renewal not being cancelled if the user message handler threw an exception.

Another big plus is that it contains my fix

Ignore scheduled/deferred messages when computing scale monitor metrics.

Which makes functions no longer scale out unnecessarily when using scheduled/deferred messages. I remember you have been hit by this bug as well.

Thanks for giving it a spin!

Regards,
Daniel

jens · July 6, 2022, 7:55am

Thanks Daniel.

You were right about having a transitive dependency to Microsoft.Azure.WebJobs.Extensions.ServiceBus 5.2.0 which in turn had a dependency on Azure.Messaging.ServiceBus 7.5.1.

Upgraded to 5.5.1 which upgraded the Azure.Messaging.ServiceBus to 7.8.1.

Deploying right now, will get back to you here after it’s been running for a while as the exceptions was random and a bit hard to force.

Going on vaccation tomorrow, so I might not be able to confirm for a couple of weeks, but it will give it a chance to run undisturbed for quite some time

//J

danielmarbach · July 6, 2022, 11:37am

That nice feeling to see the data center burn while sipping cocktails at the beach

jens · August 9, 2022, 7:06am

Hello again. Now this has been running for a couple of weeks, but unfortunately we still see the same exceptions. The only difference now is that the log says it’s from the upgraded assembly 7.8.1.0:

jens · September 5, 2022, 11:29am

After talking to @andreasohlund we tried to increase the interval of the timer trigger that previously only sent one message to itself every 10 minutes to send every 30 seconds (as I said earlier, this is currently the only activity until we activate the producers of events that this endpoint consumes).

After this we haven’t seen any exceptions at all, leading us to think that it might have something to do with the Azure Function Service Bus trigger waking up from idle state and performing something extremely fast (the Message Handler on the endpoint only did a debug log then returned Task.CompletedTask).

Any other ideas?

SeanFeldman · September 5, 2022, 10:31pm

@jens to clarify, did you increase the time from 10 seconds or to 30?

Also, have you tried creating kickoff messages w/o NServiceBus and see if the same issue could be reproduced? Thank you.

jens · September 6, 2022, 4:05am

I changed the producer (a timer trigger) from sending every 10 minutes to send every 30 seconds.

I’ve not yet tried to set it up w/o NSB. Will go ahead and try that when I’m able. To replicate what NSB does, I need a Service Bus trigger that doesn’t autocomplete the message and a binding to some SB-client where I can manually ACK the message, right?

SeanFeldman · September 6, 2022, 6:13am

So you went from a higher interval to a lower interval. Interesting…

I need a Service Bus trigger that doesn’t autocomplete the message and a binding to some SB-client where I can manually ACK the message, right?

Correct. Using the Isolated worker SDK, you can’t manually complete messages. If you’re on the In-Process SDK, you’ll need ServiceBusMessageActions to be injected and use it to complete the messages.