Azure Servicebus Queue function trigger called twice

Question

I have an Azure function with a ServiceBusTrigger that is being called twice when it is deployed to Azure. It is very easy to reproduce. Just create a new ServiceBus Trigger function and add a message to the queue.

Here's the code to send the message:

static async Task Main(string[] args)
{
    IQueueClient qc = new QueueClient(_sbConnString, "testing");

    string data = "hello";

    var msg = new Message(Encoding.UTF8.GetBytes(data));

    await qc.SendAsync(msg);
    await qc.CloseAsync();
}

Here's the function:

[FunctionName("TestTrigger")]
public static void Run([ServiceBusTrigger("testing", Connection = "myConnString")]string myQueueItem, ILogger log)
{
    log.LogInformation($"C# ServiceBus queue trigger function processed message: {myQueueItem}");
}

Log stream shows the following:

2020-03-13T23:51:23.197 [Information] Executing 'Function1' (Reason='New ServiceBus message detected on 'testing'.', Id=1b52f3c0-2497-4473-b5f9-ae406a6dee94)
2020-03-13T23:51:23.198 [Information] Trigger Details: MessageId: 9f2a7af3d4c549bb8202a013c15c0358, DeliveryCount: 1, EnqueuedTime: 3/13/2020 11:51:23 PM, LockedUntil: 3/13/2020 11:51:53 PM
2020-03-13T23:51:23.198 [Information] C# ServiceBus queue trigger function processed message: hello
2020-03-13T23:51:23.198 [Information] Executed 'Function1' (Succeeded, Id=1b52f3c0-2497-4473-b5f9-ae406a6dee94)
2020-03-13T23:51:23.197 [Information] Executing 'Function1' (Reason='New ServiceBus message detected on 'testing'.', Id=1b52f3c0-2497-4473-b5f9-ae406a6dee94)
2020-03-13T23:51:23.198 [Information] Trigger Details: MessageId: 9f2a7af3d4c549bb8202a013c15c0358, DeliveryCount: 1, EnqueuedTime: 3/13/2020 11:51:23 PM, LockedUntil: 3/13/2020 11:51:53 PM
2020-03-13T23:51:23.198 [Information] C# ServiceBus queue trigger function processed message: hello
2020-03-13T23:51:23.198 [Information] Executed 'Function1' (Succeeded, Id=1b52f3c0-2497-4473-b5f9-ae406a6dee94)

I've tried creating this on both the Mac and Windows (VSCode and VS2019 respectively) and get the same results. When I debug locally on VS2019, the trigger only gets called once.

I also checked the queue using Service Bus Explorer and only one message ends up in the queue. The trigger is just called twice.

Am I missing something simple? Looking at the log timestamps, it appears that it is being executed in parallel.

Answer 1

the real function actually imports data into a database and we are getting twice as many records because the trigger function is called twice

You should always provide the details or else the question is skewed and hard to answer. In this case, the fact that there's some work taking place in the Function that could lead to a prolonged completion of the message matters. Here's what could be happening.

Your function receives messages in PeekLock mode. The message is leased to the consumer for a certain period of time. If whatever you do in the Function takes longer than the lease time, the message will be released and Functions will retrieve it again for processing. This will take place until either Function execution is done before the lock expires (lease ends) or the message is moved to the dead-letter queue.

You should do the following:

1. Check the queue's MaxLockDuration and ensure its longer than the maximum processing time.
2. Make your function idempotent and discard messages that have already been received.