Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Queue message processed but not deleted; Job Host shut down issue? #10759

Open
oatsoda opened this issue Jan 22, 2025 · 0 comments
Open

Queue message processed but not deleted; Job Host shut down issue? #10759

oatsoda opened this issue Jan 22, 2025 · 0 comments

Comments

@oatsoda
Copy link

oatsoda commented Jan 22, 2025

Hi, I recently upgraded an Azure Functions app from in-process to isolated-process and have started to have a problem where messages are getting dequeued twice even though I don't appear to have any failures. This appear to happen very infrequently, so maybe up to 10 times a day - based upon an average daily load of about 500 queue messages. This is on a consumption plan and the issue appears to correlate with a new instance of the Function App being started up after being dormant and a new message is detected on the queue.

There appear to be no errors/exceptions in the Function.

Hosting plan: Consumption

FUNCTIONS_EXTENSION_VERSION = ~4
FUNCTIONS_WORKER_RUNTIME = dotnet-isolated
FUNCTIONS_WORKER_RUNTIME_VERSION = 8.0
WEBSITE_PLATFORM_VERSION = 103.0.7.210

Packages:
Microsoft.Azure.Functions.Worker = 1.22.0
Microsoft.Azure.Functions.Worker.Sdk" = 1.17.2
Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore = 1.2.1
Microsoft.Azure.Functions.Worker.Extensions.Storage.Queues = 5.4.0
Microsoft.Azure.Functions.Worker.ApplicationInsights" Version= 1.2.0
Microsoft.ApplicationInsights.WorkerService = 2.22.0

All important host.json settings are on the default values.

Investigating why they were dequeued twice I found that the queue message was processed but it does not appear to have been deleted, because I then see it process approx. 10 mins later - which is the default visibilityTimeout.

Here is an example of the first dequeue of one of the messages:

Invocation Id: 5bdc64e8-fbec-4290-8058-af5bffa00bff
Image

What's interesting is that the Job Host appears to shut down almost immediately after the log entry about the queue message having been processed. Additionally (not shown in the logs) is that this was the first and only message handled by this instance. So the instance started up because of this message on the queue.

Here is another example, but in this case the Job Host appears to shut down before the "New queue message detected":

Invocation Id: 4fb9f6a8-b97b-4ddd-aa82-8d2792134f05
Image

As you can see in this example, the instance started up (presumably because a new queue message was detected) but immediately decided to stop, but the queue message was dequeued and processing started.

I've checked the Function logs and can see no reason why the instance should have stopped, or why in the first example the Success message was logged but the queue message not deleted (I assume it is because the Host shut down before that delete had a chance to take place - i.e. it comes after the Success message).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant