[BUG] Lease already present after upgrading to Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3 #21511

mauve · 2021-06-02T12:50:51Z

Describe the bug

2021-06-02T12:43:49.889 [Warning] Error response [a89392d0-8a3c-44ba-b55e-8c56563e74ec] 409 There is already a lease present. (00.0s)Server:Windows-Azure-Blob/1.0,Microsoft-HTTPAPI/2.0x-ms-request-id:5a92e3cb-801e-002d-1eac-57e3e5000000x-ms-client-request-id:a89392d0-8a3c-44ba-b55e-8c56563e74ecx-ms-version:2020-04-08x-ms-error-code:LeaseAlreadyPresentDate:Wed, 02 Jun 2021 12:43:49 GMTContent-Length:221Content-Type:application/xml

Expected behavior

No warning

Actual behavior (include Exception or Stack Trace)

To Reproduce

update to 5.0.0-beta.3

Environment:

azure functions v3
dotnet core 3.1
Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3

All project dependencies:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <TargetFramework>netcoreapp3.1</TargetFramework>
    <AzureFunctionsVersion>V3</AzureFunctionsVersion>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Azure.Identity" Version="1.4.0" />
    <PackageReference Include="Azure.Messaging.ServiceBus" Version="7.2.0-beta.3" />
    <PackageReference Include="Azure.Security.KeyVault.Secrets" Version="4.1.1" />
    <PackageReference Include="Azure.Storage.Blobs" Version="12.9.0-beta.4" />
    <PackageReference Include="Microsoft.Azure.Cosmos" Version="3.19.0" />
    <PackageReference Include="Microsoft.Azure.Devices" Version="1.34.0" />
    <PackageReference Include="Microsoft.Azure.Functions.Extensions" Version="1.1.0" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions.DurableTask" Version="2.4.3" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions.Storage.Blobs" Version="5.0.0-beta.3" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions.ServiceBus" Version="5.0.0-beta.3" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions" Version="4.0.1" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Logging.ApplicationInsights" Version="3.0.27" />
    <PackageReference Include="Microsoft.Azure.WebJobs" Version="3.0.27" />
    <PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="3.1.11" />
    <PackageReference Include="Microsoft.Extensions.Logging" Version="3.1.11" />
    <PackageReference Include="Microsoft.NET.Sdk.Functions" Version="3.0.12" />
    <PackageReference Include="Microsoft.ApplicationInsights" Version="2.17.0" />
  </ItemGroup>
  <ItemGroup>
    <None Update="host.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
    </None>
    <None Update="local.settings.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
      <CopyToPublishDirectory>Never</CopyToPublishDirectory>
    </None>
  </ItemGroup>
</Project>

The text was updated successfully, but these errors were encountered:

ghost · 2021-06-02T12:54:33Z

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @xgithubtriage.

Issue Details

Describe the bug

2021-06-02T12:43:49.889 [Warning] Error response [a89392d0-8a3c-44ba-b55e-8c56563e74ec] 409 There is already a lease present. (00.0s)Server:Windows-Azure-Blob/1.0,Microsoft-HTTPAPI/2.0x-ms-request-id:5a92e3cb-801e-002d-1eac-57e3e5000000x-ms-client-request-id:a89392d0-8a3c-44ba-b55e-8c56563e74ecx-ms-version:2020-04-08x-ms-error-code:LeaseAlreadyPresentDate:Wed, 02 Jun 2021 12:43:49 GMTContent-Length:221Content-Type:application/xml

Expected behavior

No warning

Actual behavior (include Exception or Stack Trace)

To Reproduce

update to 5.0.0-beta.3

Environment:

azure functions v3
dotnet core 3.1
Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3

All project dependencies:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <TargetFramework>netcoreapp3.1</TargetFramework>
    <AzureFunctionsVersion>V3</AzureFunctionsVersion>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Azure.Identity" Version="1.4.0" />
    <PackageReference Include="Azure.Messaging.ServiceBus" Version="7.2.0-beta.3" />
    <PackageReference Include="Azure.Security.KeyVault.Secrets" Version="4.1.1" />
    <PackageReference Include="Azure.Storage.Blobs" Version="12.9.0-beta.4" />
    <PackageReference Include="Microsoft.Azure.Cosmos" Version="3.19.0" />
    <PackageReference Include="Microsoft.Azure.Devices" Version="1.34.0" />
    <PackageReference Include="Microsoft.Azure.Functions.Extensions" Version="1.1.0" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions.DurableTask" Version="2.4.3" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions.Storage.Blobs" Version="5.0.0-beta.3" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions.ServiceBus" Version="5.0.0-beta.3" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Extensions" Version="4.0.1" />
    <PackageReference Include="Microsoft.Azure.WebJobs.Logging.ApplicationInsights" Version="3.0.27" />
    <PackageReference Include="Microsoft.Azure.WebJobs" Version="3.0.27" />
    <PackageReference Include="Microsoft.Extensions.DependencyInjection.Abstractions" Version="3.1.11" />
    <PackageReference Include="Microsoft.Extensions.Logging" Version="3.1.11" />
    <PackageReference Include="Microsoft.NET.Sdk.Functions" Version="3.0.12" />
    <PackageReference Include="Microsoft.ApplicationInsights" Version="2.17.0" />
  </ItemGroup>
  <ItemGroup>
    <None Update="host.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
    </None>
    <None Update="local.settings.json">
      <CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
      <CopyToPublishDirectory>Never</CopyToPublishDirectory>
    </None>
  </ItemGroup>
</Project>

Author:	mauve
Assignees:	-
Labels:	`Client`, `Service Attention`, `Storage`, `customer-reported`, `needs-team-attention`, `needs-triage`, `question`
Milestone:	-

amnguye · 2021-06-07T20:05:04Z

What version of Microsoft.Azure.WebJobs.Extensions.Storage are you upgrading from?

Also what code snippet causes the 409 Lease already present error?

kasobol-msft · 2021-06-29T15:47:07Z

This is most likely coming from

azure-sdk-for-net/sdk/storage/Microsoft.Azure.WebJobs.Extensions.Storage.Blobs/src/Listeners/BlobReceiptManager.cs

Lines 125 to 144 in 0e7a91c

    
           try 
        
           { 
        
               BlobLease lease = await blob.GetBlobLeaseClient().AcquireAsync(LeasePeriod, cancellationToken: cancellationToken).ConfigureAwait(false); 
        
               return lease.LeaseId; 
        
           } 
        
           catch (RequestFailedException exception) 
        
           { 
        
               if (exception.IsConflictLeaseAlreadyPresent()) 
        
               { 
        
                   return null; 
        
               } 
        
               else if (exception.IsNotFoundBlobOrContainerNotFound()) 
        
               { 
        
                   // If someone deleted the receipt, there's no lease to acquire. 
        
                   return null; 
        
               } 
        
               else 
        
               { 
        
                   throw; 
        
               }

. We'll look for ways to not report that warning.

amnguye · 2021-08-05T20:18:05Z

Relabeling as bug

leniency · 2021-11-05T23:47:18Z

This is still happening in the 5.0 release.

mdarefull · 2021-11-10T10:39:07Z

In case it helps,

I have one Consumption Function App with 3 functions: (simplified)

public Task<ActionResult> Post(
      [HttpTrigger(AuthorizationLevel.Anonymous, nameof(HttpMethods.Post))] HttpRequest httpRequest,
      [Blob("%DocumentsUploadContainer%/{rand-guid}", FileAccess.ReadWrite)] BlobClient blobClient,
      [Queue("%DocumentsUploadQueue%")] IAsyncCollector<DocumentMetadata> documentUploadMessages,
      CancellationToken cancellationToken) {...}

public Task ProcessScheduledDocumentUpload(
      [QueueTrigger("%DocumentsUploadQueue%")] DocumentMetadata metadata, string id, string popReceipt, long dequeueCount,
      [Blob("%DocumentsUploadContainer%/{blobName}", FileAccess.ReadWrite)] BlobClient blobClient,
      [Queue("%DocumentsUploadQueue%")] QueueClient queueClient) {...}

public Task CleanUpSessions(
      [TimerTrigger("%OnBaseSessionsMonitorSchedule%")] TimerInfo timer)

This function app has a dedicated storage account to which all functions refer to through the AzureWebJobsStorage App Settings variable.

This warning log is being generated ~70K times a day. This not only impacts the $$$ and the adaptive sampling features of my App Insight component, but since they are warning, they make it pretty hard to review the logs.

jedjohan · 2021-11-11T07:56:09Z

This is still happening in the 5.0 release.

Yes, also seeing it

StephenCleary · 2021-11-17T03:04:50Z

Just updated to the new .NET 6.0 with latest (non-prerelease) libraries and ~4 runtime (in-proc C# library), and this issue still occurs.

If you want to stem the AI log spam, setting Azure.Core to Error in your host.json seems to stop it:

{
  "version": "2.0",
  "logging": {
    "logLevel": {
      "default": "Information",
      "Azure.Core": "Error"
    }
  }
}

This unfortunately turns off all of the Azure.Core logs, most particularly ResponseDelay which warns of slow function times.

For in-process function apps at least, there's a name deduplication that happens so that ResponseDelay is reported with category Azure.Core.1 instead of Azure.Core. So you might be able to include that one in your logs by adding "Azure.Core.": "Warning" to your host.json logging configuration. I haven't tried it since I have my own warning log message when a function takes too long.

JohanKlijn · 2021-11-23T11:24:50Z

FYI, I am using version 4.0.5 of Microsoft.Azure.WebJobs.Extensions.Storage, and I am seeing the same issue. Between the 7 and 20 lines per minute.

amishra-dev · 2021-12-01T00:57:16Z

@jaschrep-msft can you please pick this up.

tg-msft · 2021-12-01T20:50:57Z

We'd like the fix for this to align with #25626 which we hope will be a common solution to this class of problems.

shanselman · 2022-01-07T23:08:28Z

I'm hitting this as well, here in the first week of Jan

braddwalker · 2022-01-23T17:39:10Z

This bug is a spam cannon for my logs

maQus123 · 2022-02-16T10:33:32Z

Our log is flooded as well, any news on this?

jim-hart-dev · 2022-03-14T06:18:34Z

We're also seeing this. Any update? This is coming from our durable functions app, in a container in AKS. .net 6, functions v4

Error response [34d137f5-9af7-4e51-9203-a78120bbb4af] 409 There is already a lease present. (00.0s)
Server:Windows-Azure-Blob/1.0,Microsoft-HTTPAPI/2.0
x-ms-error-code:LeaseAlreadyPresent
SourceContext: Azure.Core

Project file

<Project Sdk="Microsoft.NET.Sdk">
	<PropertyGroup>
	  <TargetFramework>net6.0</TargetFramework>
	  <LangVersion>latestMajor</LangVersion>
		<AzureFunctionsVersion>v4</AzureFunctionsVersion>
		<DockerDefaultTargetOS>Linux</DockerDefaultTargetOS>
	</PropertyGroup>
	<PropertyGroup>
		<ServerGarbageCollection>false</ServerGarbageCollection>
	</PropertyGroup>
	<PropertyGroup Condition="'$(Configuration)|$(Platform)'=='Release|AnyCPU'">
		<TreatWarningsAsErrors>true</TreatWarningsAsErrors>
		<NoWarn>1701;1702;AD0001</NoWarn>
	</PropertyGroup>
	<PropertyGroup Condition="'$(Configuration)|$(Platform)'=='Debug|AnyCPU'">
		<TreatWarningsAsErrors>true</TreatWarningsAsErrors>
		<NoWarn>1701;1702;AD0001</NoWarn>
	</PropertyGroup>
	<ItemGroup>
		<PackageReference Include="Azure.Messaging.ServiceBus" Version="7.5.1" />
		<PackageReference Include="Azure.Storage.Queues" Version="12.8.0" />
		<PackageReference Include="Microsoft.Azure.Functions.Extensions" Version="1.1.0" />
		<PackageReference Include="Microsoft.Azure.WebJobs.Extensions.DurableTask" Version="2.6.1" />
		<PackageReference Include="Microsoft.Azure.WebJobs.Extensions.Storage" Version="5.0.0" />
		<PackageReference Include="Microsoft.Extensions.Diagnostics.HealthChecks.Abstractions" Version="6.0.1" />
		<PackageReference Include="Microsoft.NET.Sdk.Functions" Version="4.0.1" />
		<PackageReference Include="Microsoft.VisualStudio.Azure.Containers.Tools.Targets" Version="1.14.0" />
		<PackageReference Include="Serilog.AspNetCore" Version="4.1.0" />
		<PackageReference Include="Serilog.Exceptions" Version="8.0.0" />
		<PackageReference Include="Serilog.Expressions" Version="3.2.1" />
		<PackageReference Include="Serilog.Extensions.WebJobs" Version="0.6.1" />
		<PackageReference Include="Serilog.Formatting.Compact" Version="1.1.0" />
		<PackageReference Include="Serilog.Sinks.AzureServiceBus" Version="1.0.2" />
	</ItemGroup>
	<ItemGroup>
		<None Update="host.json">
			<CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
		</None>
		<None Update="local.settings.json">
			<CopyToOutputDirectory>PreserveNewest</CopyToOutputDirectory>
			<CopyToPublishDirectory>Never</CopyToPublishDirectory>
		</None>
		<None Update="serilog.settings.json">
			<CopyToOutputDirectory>Always</CopyToOutputDirectory>
		</None>
	</ItemGroup>
</Project>

melborp · 2022-06-07T19:37:40Z

I'd like to add and raise awareness why these issues should be taken quite seriously by product group.

The impact is two-fold:

Noisy logging that is driving up the application insights costs due to low value trace messages. Messages such as "Lease already present", "Skipping ownership lease aquiring for somefunctionapp-control-... ". Yes, your customers are paying for these messages.
Some of these behaviors (e.g. blobtrigger scanning change between v3 and v4) cause unnecessary load on storage account which is harder to notice due to infinite cloud scale, until you notice the cost rise due to storage account usage (which then also causes Azure Defender Costs to rise).

I've been hit by this twice now - once for non-durable functions with blob triggers that went on spiral trying to understand if retriggering is necessary and causes both insane blob storage usage growth and trace logging. This happened while migration from v3 to v4 and to .net 6.
As mentioned here: "Azure.Core": "Error" helps with less trace logs, but to "fix" the storage usage, we had to move away from blob triggers to eventgrid + servicebus triggering instead. On one of the most used storage account, the problem caused 8 million additional transactions on storage per day for us. Add that we have about 10 environments and more than one storage account per environment - its becomes a noticeable cost and mess.

The second one is the durable function and the "Skipping ownership lease aquiring for somefunctionapp-control-". Its not merely an info message, your storage is being hit here as well (at least mine is). About 1.2 million transactions/day on the most used storage account linked to function app. I've yet to understand what is causing this, since the particular durable function for us is not in active usage - but it started after .net 6 / v4 migration.

anirudhgarg · 2022-06-17T05:56:17Z

@kasobol-msft and @jaschrep-msft are you looking at this ? Many customers are facing this.

yoichiozaki · 2022-10-12T09:16:03Z

@kasobol-msft @jaschrep-msft
My customer is complaining of the same symptoms, and they are also being charged unnecessarily for Log Analytics, so the problem needs to be resolved as soon as possible.
Will filtering by log level prevent unnecessary charges for Log Analytics?

annelo-msft · 2023-01-10T00:44:14Z

The required APIs should be available now in Azure.Core to be able to implement this feature. In order to suppress distributed tracing for a given status code, AddClassifier() should be called on RequestContext prior to passing it to the method in question. An example can be found in the TableServiceClient here.

Please reach out with any remaining questions on implementation.

xmak · 2023-02-11T21:27:10Z

When can we expect this to be fixed?

jaschrep-msft · 2023-02-27T15:26:09Z

@xmak the PR linked above your comment is the key to fixing this. We plan to get this out in our next release cycle. Once that API is available, the webjobs extension package will need to be updated to use the new API instead of the old one, passing in the appropriate error classification to avoid logging the response.

ghost removed the needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. label Jun 2, 2021

kasobol-msft self-assigned this Jun 28, 2021

amnguye added bug This issue requires a change to an existing behavior in the product in order to be resolved. and removed question The issue doesn't require a change to the product in order to be resolved. Most issues start as that labels Aug 5, 2021

jsquire added this to the Backlog milestone Aug 9, 2021

TurakKatase mentioned this issue Sep 27, 2021

Function App logs frequently getting "409 There is already a lease present" warnings Azure/azure-functions-durable-extension#1959

Closed

lmolkova mentioned this issue Nov 12, 2021

Remove ErrorOptions Azure/azure-sdk-for-java#25338

Merged

kasobol-msft assigned jaschrep-msft and unassigned kasobol-msft Nov 18, 2021

annelo-msft mentioned this issue Nov 30, 2021

[LLC] Move RequestOptions into Core Azure/autorest.csharp#1666

Closed

tg-msft mentioned this issue Dec 1, 2021

Expose RequestOptions for HLC methods causing noisy logs/tracing #25626

Closed

9 tasks

mmalka mentioned this issue Dec 24, 2021

[QUERY] nvm #26048

Closed

tg-msft mentioned this issue Mar 18, 2022

[Draft] Minimize noisy Storage exceptions via DPG methods #27645

Closed

kasobol-msft mentioned this issue Jun 6, 2022

[FEATURE REQ] Storage extensions should leverage RequestContext.ErrorOptions #29132

Closed

jaschrep-msft mentioned this issue Jan 26, 2023

BlobLeaseClient Avoid Log 409 response #33695

Merged

jaschrep-msft mentioned this issue Mar 7, 2023

Storage Webjobs BlobReciptManager Classifies "LeaseAlreadyPresent" #34752

Merged

jaschrep-msft closed this as completed in #34752 Mar 8, 2023

jaschrep-msft mentioned this issue Apr 4, 2023

"409 The specified container already exists." Azure/Azure-Functions#2166

Open

github-actions bot locked and limited conversation to collaborators Jun 6, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[BUG] Lease already present after upgrading to Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3 #21511

[BUG] Lease already present after upgrading to Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3 #21511

mauve commented Jun 2, 2021

ghost commented Jun 2, 2021

amnguye commented Jun 7, 2021

kasobol-msft commented Jun 29, 2021

amnguye commented Aug 5, 2021

leniency commented Nov 5, 2021

mdarefull commented Nov 10, 2021

jedjohan commented Nov 11, 2021

StephenCleary commented Nov 17, 2021

JohanKlijn commented Nov 23, 2021

amishra-dev commented Dec 1, 2021

tg-msft commented Dec 1, 2021

shanselman commented Jan 7, 2022

braddwalker commented Jan 23, 2022

maQus123 commented Feb 16, 2022

jim-hart-dev commented Mar 14, 2022 •

edited

Loading

melborp commented Jun 7, 2022 •

edited

Loading

anirudhgarg commented Jun 17, 2022

yoichiozaki commented Oct 12, 2022

annelo-msft commented Jan 10, 2023

xmak commented Feb 11, 2023

jaschrep-msft commented Feb 27, 2023 •

edited

Loading

[BUG] Lease already present after upgrading to Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3 #21511

[BUG] Lease already present after upgrading to Microsoft.Azure.WebJobs.Extensions.Storage 5.0.0-beta.3 #21511

Comments

mauve commented Jun 2, 2021

ghost commented Jun 2, 2021

amnguye commented Jun 7, 2021

kasobol-msft commented Jun 29, 2021

amnguye commented Aug 5, 2021

leniency commented Nov 5, 2021

mdarefull commented Nov 10, 2021

jedjohan commented Nov 11, 2021

StephenCleary commented Nov 17, 2021

JohanKlijn commented Nov 23, 2021

amishra-dev commented Dec 1, 2021

tg-msft commented Dec 1, 2021

shanselman commented Jan 7, 2022

braddwalker commented Jan 23, 2022

maQus123 commented Feb 16, 2022

jim-hart-dev commented Mar 14, 2022 • edited Loading

melborp commented Jun 7, 2022 • edited Loading

anirudhgarg commented Jun 17, 2022

yoichiozaki commented Oct 12, 2022

annelo-msft commented Jan 10, 2023

xmak commented Feb 11, 2023

jaschrep-msft commented Feb 27, 2023 • edited Loading

jim-hart-dev commented Mar 14, 2022 •

edited

Loading

melborp commented Jun 7, 2022 •

edited

Loading

jaschrep-msft commented Feb 27, 2023 •

edited

Loading