Azure Function - service bus message sometimes take long time to recieve

[petrkasnal]

Hello,

I have an application where there is one part WebApi (which as you can tell by the name is a webapi app service) and another part Worker (which is an Azure Function). They communicate with each other using Azure Service Bus. The WebApi service calls the Worker - the Started message, and the Worker calls back the WebApi - the Finished message. Everything works quite fine and as it should. The messages don't run extremely often. Mostly once an hour and they don't even run over each other.

However, once a day, typically at 06:00 am, the messages take an extremely long time to send. Roughly 1-2 minutes. Then because of this the state machine also malfunctions ) in my opinion some message expires. Otherwise messages are processed in seconds. For a while I thought it was due to cold start. But the message goes slowly to Worker and to WebApi. I'm getting desperate about this because I can't find any more info. These logs are info from the consumer method. Where there is no other code before the log.

I don't see any errors in the log. The only thing in the log is the occasional message. Which is a known problem and quite annoying Result: Cancelled Exception: Grpc.Core.RpcException: Status(StatusCode="Cancelled", Detail="Call canceled by the client.", DebugException="System.OperationCanceledException: The operation was canceled.") ---> System.OperationCanceledException: The operation was canceled. --- End of inner exception stack trace --- at Microsoft.Azure.Functions.Worker.ServiceBusMessageActions.CompleteMessageAsync(ServiceBusReceivedMessage message, CancellationToken cancellationToken) in D:\a\_work\1\s\extensions\Worker.Extensions.ServiceBus\src\ServiceBusMessageActions.cs:line 78 at Worker.FunctionApp.DefaultServiceBusFunction.AsTopicResultWithCompleteMessage[TConsumer](ServiceBusReceivedMessage message, ServiceBusMessageActions messageActions, String topic, String subs, CancellationToken cancellationToken) in D:\a\1\s\Src\Worker.FunctionApp\DefaultServiceBusFunction.cs:line 50 at Worker.FunctionApp.Started.Run(ServiceBusReceivedMessage message, ServiceBusMessageActions messageActions, CancellationToken cancellationToken) in D:\a\1\s\Src\Worker.FunctionApp\Started.cs:line 24 at Worker.FunctionApp.DirectFunctionExecutor.ExecuteAsync(FunctionContext context) in D:\a\1\s\Src\Worker.FunctionApp\obj\Release\net8.0\Microsoft.Azure.Functions.Worker.Sdk.Generators\Microsoft.Azure.Functions.Worker.Sdk.Generators.FunctionExecutorGenerator\GeneratedFunctionExecutor.g.cs:line 39 at Microsoft.Azure.Functions.Worker.OutputBindings.OutputBindingsMiddleware.Invoke(FunctionContext context, FunctionExecutionDelegate next) in D:\a\_work\1\s\src\DotNetWorker.Core\OutputBindings\OutputBindingsMiddleware.cs:line 13 at Microsoft.Azure.Functions.Worker.FunctionsApplication.InvokeFunctionAsync(FunctionContext context) in D:\a\_work\1\s\src\DotNetWorker.Core\FunctionsApplication.cs:line 91 at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.InvokeAsync(InvocationRequest request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 88 Stack: at Microsoft.Azure.Functions.Worker.ServiceBusMessageActions.CompleteMessageAsync(ServiceBusReceivedMessage message, CancellationToken cancellationToken) in D:\a\_work\1\s\extensions\Worker.Extensions.ServiceBus\src\ServiceBusMessageActions.cs:line 78 at Worker.FunctionApp.DefaultServiceBusFunction.AsTopicResultWithCompleteMessage[TConsumer](ServiceBusReceivedMessage message, ServiceBusMessageActions messageActions, String topic, String subs, CancellationToken cancellationToken) in D:\a\1\s\Src\Worker.FunctionApp\DefaultServiceBusFunction.cs:line 50 at Worker.FunctionApp.Started.Run(ServiceBusReceivedMessage message, ServiceBusMessageActions messageActions, CancellationToken cancellationToken) in D:\a\1\s\Src\Worker.FunctionApp\Started.cs:line 24 at Worker.FunctionApp.DirectFunctionExecutor.ExecuteAsync(FunctionContext context) in D:\a\1\s\Src\Worker.FunctionApp\obj\Release\net8.0\Microsoft.Azure.Functions.Worker.Sdk.Generators\Microsoft.Azure.Functions.Worker.Sdk.Generators.FunctionExecutorGenerator\GeneratedFunctionExecutor.g.cs:line 39 at Microsoft.Azure.Functions.Worker.OutputBindings.OutputBindingsMiddleware.Invoke(FunctionContext context, FunctionExecutionDelegate next) in D:\a\_work\1\s\src\DotNetWorker.Core\OutputBindings\OutputBindingsMiddleware.cs:line 13 at Microsoft.Azure.Functions.Worker.FunctionsApplication.InvokeFunctionAsync(FunctionContext context) in D:\a\_work\1\s\src\DotNetWorker.Core\FunctionsApplication.cs:line 91 at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.InvokeAsync(InvocationRequest request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 88

Thank you

[bhagyshricompany]

Thanks for reporting Can you ty again & pls share the func app name,time stamp region where you deployed.

[petrkasnal]

Thanks for reporting Can you ty again & pls share the func app name,time stamp region where you deployed.

Thank you for reply. Yea sure: Azure Function North Europe osgber-f-deepappchecks-test

Azure Service bus: North Europe osgber-servicebus-test

The problem happens more often. Sometimes the function runs for a second and sometimes 1-2 minutes. It's not at the same time and it's completely random.

Send time - Recieve time 10/1/2024, 4:34:09.210 AM - 10/1/2024, 4:36:27.483 AM 9/29/2024, 8:33:53.594 PM - 9/29/2024, 8:35:27.859 PM 9/29/2024, 12:34:33.667 PM - 9/29/2024, 12:35:59.050 PM

[bhagyshricompany]

can you check it again and configure seems working fine created one sample function.

[petrkasnal]

@bhagyshricompany It happens all the time. Same exact scenario. Once every 1-2 days.

[bhagyshricompany]

@kshyju please comment .Thanks

[surgupta-msft]

@petrkasnal apologies for the delayed response here. Can you please check if you are still facing this issue with the latest packages?

[microsoft-github-policy-service[bot]]

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 4 days. It will be closed if no further activity occurs within 3 days of this comment.

If you are not the original author (@petrkasnal) and believe this issue is not stale, please comment with /bot not-stale and I will not close it.