blidea
blidea

Reputation: 25

Azure storage queue/functions, dequeue from poison queue only once

I have a problem with azure storage functions+azure storage queue. I have a queue - "myQueue" and queue-triggered azure function "func1". In host.json I've configured maxDequeueCount(5) and visibilityTimeout - everything works nice.

After 5 tries my message goes to "myQueue-poison". I have second azure function "func2"(copy paste from func1), which is queue-triggered from "myQueue-poison". I've also set maxDequeueCount and visibilityTimeout in host.json for this function. But this function is triggered only once - after first failed run my message disappears from queue. What's wrong? host.json and c# code are identical - only the name of the queue is different.

Below is the code from Function 1 and Function 2.

[FunctionName("Function1")]
        public static void Run([QueueTrigger("myqueue-poison", Connection = "AzureWebJobsStorage")]string myQueueItem, ILogger log)
        {
            Exception ex = new Exception();
            throw ex;
        }



 [FunctionName("Function2")]
        public static void Run([QueueTrigger("myqueue", Connection = "AzureWebJobsStorage")]string myQueueItem, ILogger log)
        {
            Exception ex = new Exception();            
            throw ex;
        }

Sample log message where there is delay in messages getting processed from poison queue.

 [12/5/2018 9:39:16 PM] Loading functions metadata
    [12/5/2018 9:39:16 PM] 2 functions loaded
    [12/5/2018 9:39:17 PM] Generating 2 job function(s)
    [12/5/2018 9:39:17 PM] Found the following functions:
    [12/5/2018 9:39:17 PM] FunctionApp1.Function1.Run
    [12/5/2018 9:39:17 PM] FunctionApp1.Function2.Run
    [12/5/2018 9:39:17 PM]
    [12/5/2018 9:39:17 PM] Host initialized (662ms)
    [12/5/2018 9:39:17 PM] Host started (707ms)
    [12/5/2018 9:39:17 PM] Job host started
    Hosting environment: Production
    Content root path: C:\Users\username\source\repos\FunctionApp1\FunctionApp1\bin\Debug\netstandard2.0
    Now listening on: http://0.0.0.0:7071
    Application started. Press Ctrl+C to shut down.
    [12/5/2018 9:39:18 PM] Executing 'Function2' (Reason='New queue message detected on 'myqueue'.', Id=20bf83c5-3142-4092-9d85-7a2a6fbcf863)
    [12/5/2018 9:39:18 PM] Executed 'Function2' (Failed, Id=20bf83c5-3142-4092-9d85-7a2a6fbcf863)
    [12/5/2018 9:39:18 PM] System.Private.CoreLib: Exception while executing function: Function2. FunctionApp1: Exception of type 'System.Exception' was thrown.
    [12/5/2018 9:39:18 PM] Executing 'Function2' (Reason='New queue message detected on 'myqueue'.', Id=49775db2-0c91-41cb-b472-a3aceee1bac3)
    [12/5/2018 9:39:19 PM] Executed 'Function2' (Failed, Id=49775db2-0c91-41cb-b472-a3aceee1bac3)
    [12/5/2018 9:39:19 PM] System.Private.CoreLib: Exception while executing function: Function2. FunctionApp1: Exception of type 'System.Exception' was thrown.
    [12/5/2018 9:39:19 PM] Executing 'Function2' (Reason='New queue message detected on 'myqueue'.', Id=0a1d103a-41a0-4630-a479-c72297a368b8)
    [12/5/2018 9:39:19 PM] Executed 'Function2' (Failed, Id=0a1d103a-41a0-4630-a479-c72297a368b8)
    [12/5/2018 9:39:19 PM] System.Private.CoreLib: Exception while executing function: Function2. FunctionApp1: Exception of type 'System.Exception' was thrown.
    [12/5/2018 9:39:19 PM] Executing 'Function2' (Reason='New queue message detected on 'myqueue'.', Id=6b79aad1-1eb6-4cfe-b39c-a7078f006968)
    [12/5/2018 9:39:20 PM] Executed 'Function2' (Failed, Id=6b79aad1-1eb6-4cfe-b39c-a7078f006968)
    [12/5/2018 9:39:20 PM] System.Private.CoreLib: Exception while executing function: Function2. FunctionApp1: Exception of type 'System.Exception' was thrown.
    [12/5/2018 9:39:20 PM] Executing 'Function2' (Reason='New queue message detected on 'myqueue'.', Id=cf401aee-133d-42ac-a8e0-25fe95ebe162)
    [12/5/2018 9:39:20 PM] Executed 'Function2' (Failed, Id=cf401aee-133d-42ac-a8e0-25fe95ebe162)
    [12/5/2018 9:39:20 PM] System.Private.CoreLib: Exception while executing function: Function2. FunctionApp1: Exception of type 'System.Exception' was thrown.
    [12/5/2018 9:39:20 PM] Message has reached MaxDequeueCount of 5. Moving message to queue 'myqueue-poison'.
    [12/5/2018 9:39:20 PM] Executing 'Function1' (Reason='New queue message detected on 'myqueue-poison'.', Id=2b1bd5ec-67e2-41c9-bd7b-6a3fde48cd04)
    [12/5/2018 9:39:21 PM] Executed 'Function1' (Failed, Id=2b1bd5ec-67e2-41c9-bd7b-6a3fde48cd04)
    [12/5/2018 9:39:21 PM] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp1: Exception of type 'System.Exception' was thrown.
    [12/5/2018 9:39:22 PM] Host lock lease acquired by instance ID '0000000000000000000000004EE22C73'.
[12/5/2018 9:49:20 PM] Executing 'Function1' (Reason='New queue message detected on 'myqueue-poison'.', Id=83f83d31-44e6-46cf-a235-08360e5adc60)
[12/5/2018 9:49:21 PM] Executed 'Function1' (Failed, Id=83f83d31-44e6-46cf-a235-08360e5adc60)
[12/5/2018 9:49:21 PM] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp1: Exception of type 'System.Exception' was thrown.
[12/5/2018 9:59:21 PM] Executing 'Function1' (Reason='New queue message detected on 'myqueue-poison'.', Id=54acbb91-d4db-4737-ae90-47b17df5998c)
[12/5/2018 9:59:21 PM] Executed 'Function1' (Failed, Id=54acbb91-d4db-4737-ae90-47b17df5998c)
[12/5/2018 9:59:21 PM] System.Private.CoreLib: Exception while executing function: Function1. FunctionApp1: Exception of type 'System.Exception' was thrown.

So it looks like the messages from poison queue are not read in the same way as normal queues. Are there any configuration which can be used to reduce the delay in processing from poison queue ?

Upvotes: 1

Views: 2151

Answers (1)

Ling Toh
Ling Toh

Reputation: 2474

This is not a supported scenario at the moment.

If the queue is already a poison queue, no subsequent poison queue will be created for the poison queue. Kindly see implementation here.

Since there is no 2nd poison queue for your poison-queue, the message will not be released while your Function is still running, i.e. it may take 10 minutes before you will see the message again. Kindly see implementation here.

Upvotes: 4

Related Questions