Blob trigger delay and issues

[ELToulemonde]

We developed an Azure Function in python which is blob triggered on certain blobs. It run on a service plan.

We sometimes encounter very weird behavior of blob triggers.

Delay
First, there is sometimes a very huge delay between blob creation and trigger insertion. Here is a Trigger log :

Trigger Details: MessageId: <some message id>, DequeueCount: 1, InsertedOn: 2024-02-14T12:26:28.000+00:00, BlobCreated: 2024-02-14T06:16:26.000+00:00, BlobLastModified: 2024-02-14T06:16:27.000+00:00

As one can see, the blob was created and last modified at 06:16, and the trigger append at 12:26pm. I can't find in the documentation any reason for such a delay.

Really weird requeue behavior
When function fails (for some reason that are not related to this question), the requeue behavior is not working as expected. Here are the Trigger details that I can find in my logs :

Trigger Details: MessageId: 399ec....identical, DequeueCount: 1, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 2, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 2, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 4, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 3, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 3, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 3, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 4, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 4, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 5, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 5, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 5, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00
Trigger Details: MessageId: 399ec....identical, DequeueCount: 5, InsertedOn: 2024-02-13T11:25:32.000+00:00, BlobCreated: 2024-02-13T10:31:30.000+00:00, BlobLastModified: 2024-02-13T10:31:31.000+00:00

What I find very weird is that, DequeueCount is not 1, 2, 3, 4, 5 but 1, 2, 2, 3, 3, 3, etc. This make the function try 13 times instead of 5 times which is the MaxDequeueCount

Investigative information

Please provide the following:

• Timestamp: 2024/02/14
• Function App version: 4
• Function App name: I don't wish to disclose publicly
• Function name(s) (as appropriate):
• Invocation ID: 47437051-65f4-48e4-a6bf-dc57ce04edae
• Region: France Central

Repro steps

I'm not sure how to reproduce.

Expected behavior

• Delay of a few seconds / minutes
• Linear dequeue

Actual behavior

• Delay of a few hours
• Dequeue count 1, 2, 2, 3, 3, 3, 4, 4, etc for same function retry

Thanks

[AartBluestoke]

There are 2 ways blob triggers check for updates. both are known to be broken.

there are known significant blob trigger issues if

a) you are using a connection string to read from a different container that that hosting the function

• this breaks the log follower which only follows the webjobs.
• the logFollower is normally quite good at picking the newest updates, but fails to keep up if you have >100 updates/second
  b) you have more than 10,000 blobs in the container.
• the 'scan all blobs, checking for changes' follower breaks if you have over 10,000 blobs, as it checks them 10,000 at a time and fails to keep timestamps correctly, so can miss updates in the early batches if updates occur in the later batches at the same time.
  c) you don't insert/update only the alphabetically last blobs in the container.
• this is to make updates occur across multiple batches of the blob scan (which reads the first 10k, then the next 10k,... then the last 10k, and sets the high water mark to the highest timestamp found in any batch, which may be after the time it read the first one.

see Azure/azure-webjobs-sdk#3029
and
Azure/azure-webjobs-sdk#3023

the consequences of this is 1 lone update may be permanently missed until the next restart of the function app.
if there are multiple triggers for the same file, the next one will run the same probabilistic hit/miss

[JAdluri]

Hello @ELToulemonde could you please let me know if the above explanation refers to your function app behaviour and is that addressed.

[jwdb]

Considering the two issues mentioned above are still open and relevant, closing this issue automatically would be premature in my opinion. I'm actively watching this issue in the hope it gets resolved and I can communicate with my customer their grievances are over.

/bot not-stale

[AartBluestoke]

@jwdb - do you know of a way we can get attention on the linked issues?

[ELToulemonde]

Hello @ELToulemonde could you please let me know if the above explanation refers to your function app behaviour and is that addressed.

Hello,
I moved away from blob trigger to use an event grid, that seems more reliable.

Thanks.