Azure / azure-functions-dotnet-worker

Azure Functions out-of-process .NET language worker
MIT License
412 stars 176 forks source link

Azure function intermittent error during cold start after converting to .NET 8 isolated worker #2610

Open YaseenElmaandy opened 1 month ago

YaseenElmaandy commented 1 month ago

What version of .NET does your existing project use?

.NET 6

What version of .NET are you attempting to target?

.NET 8

Description

I have an Http Trigger Azure function that has been working fine for the past years, It is an Azure Function running on a Windows Consumption App Service Plan, I recently updated from .NET6 in-process to .NET8 isolated worker model.

After the upgrade to isolated worker, I am now seeing intermittent errors when calling the function, the function seems to crash after a cold start and errors are written to AppInsights.

Calling the function a second time minutes later the call will succeed and then subsequent calls will generally work for a while. Then we will typically see another error after the next cold start - although not always - sometimes it works fine.

The error I receive is :

I tried updating all the libraries to the latest version and increasing the function timeout to 10 minutes, but still the issue exist.

One thing that reduces the issue to 1 or 2 times per day is this variation of libraries versions :

<PackageReference Include="Microsoft.Azure.Functions.Worker" Version="1.22.0" /> 

<PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.2.0" />

<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.3.0"/> 

<PackageReference Include="Microsoft.Azure.Functions.Worker.Sdk" Version="1.17.2" />

I want to add that this happened to all Http-triggered Azure functions we have at different Azure function apps. and we never had these exceptions before migration.

Project configuration and dependencies

That's my Program.cs file :

var host = new HostBuilder()
    .ConfigureFunctionsWebApplication()
    .ConfigureServices((context, services) =>
    {
        var configuration = new ConfigurationBuilder()
                .AddEnvironmentVariables()
                .Build();
        var applicationInsightsConnectionString = "connectionString";
        services.AddApplicationInsightsTelemetryWorkerService(options => options.ConnectionString = applicationInsightsConnectionString);
    })
    .Build();
host.Run();

host.js:

{
  "version": "2.0",
  "functionTimeout": "00:10:00",
  "logging": {
    "applicationInsights": {
      "samplingSettings": {
        "isEnabled": true,
        "excludedTypes": "Request"
      },
      "enableLiveMetricsFilters": true
    }
  }
}

And Packages references:

 <ItemGroup>
   <FrameworkReference Include="Microsoft.AspNetCore.App" />
   <PackageReference Include="Microsoft.Azure.Functions.Worker" Version="1.22.0" />
   <PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.CosmosDB" Version="4.9.0" />
   <PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http" Version="3.2.0" />
   <PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.3.0" />
   <PackageReference Include="Microsoft.Azure.Functions.Worker.Sdk" Version="1.17.2" />
   <PackageReference Include="Microsoft.ApplicationInsights.WorkerService" Version="2.22.0" />
   <PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.2.0" />
   <PackageReference Include="System.Formats.Asn1" Version="8.0.1" />
   <PackageReference Include="System.Text.Json" Version="8.0.4" />
 </ItemGroup>

Link to a repository that reproduces the issue

No response

rbnswartz commented 1 month ago

I'm having the same issue.

jviau commented 1 month ago
<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.30"/> 

1.30 does not exist. Is this a typo and you intended 1.3.0?

Can you try upgrading to 1.3.2?

YaseenElmaandy commented 1 month ago
<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.30"/> 

1.30 does not exist. Is this a typo and you intended 1.3.0?

Can you try upgrading to 1.3.2?

Yes, it's a typo, I meant 1.3.0. And yes I tried updating it to 1.3.2 , and it didn't work as well, I tried updating all the libraries to its latest versions and also the issue still happened

jviau commented 1 month ago

@YaseenElmaandy can you share the intermittent error you are encountering?

YaseenElmaandy commented 1 month ago

@YaseenElmaandy can you share the intermittent error you are encountering?

This one :

It happens at random times during the day, it's not consistent, it happens only for the http-triggered functions, and for all azure functions not specific one, and it never happened before migration to .NET 8 (it was .NET 6) I believe it's related to the cold start time of the function but I can't confirm it.

rbnswartz commented 1 month ago

I'm also seeing the behavior, in my case there are two other log entries that also show up Failed to proxy request with ForwarderError and An attempt was made to access a socket in a way forbidden by its access permissions.

@YaseenElmaandy are you seeing in your logs also or is this just me?

YaseenElmaandy commented 1 month ago

I'm also seeing the behavior, in my case there are two other log entries that also show up Failed to proxy request with ForwarderError and An attempt was made to access a socket in a way forbidden by its access permissions.

@YaseenElmaandy are you seeing in your logs also or is this just me?

Yes, I have these exact exceptions at some azure functions as well, not all of them but multiple ones.

This question is the same also, I replied with the same as I did here, but still no body figured it out. https://learn.microsoft.com/en-us/answers/questions/1705006/azure-function-intermittent-error-during-cold-star

jviau commented 1 month ago

Failed to proxy request with ForwarderError and An attempt was made to access a socket in a way forbidden by its access permissions

Ah got it! We are aware of this issue and are actively investigating.

YaseenElmaandy commented 1 month ago

Failed to proxy request with ForwarderError and An attempt was made to access a socket in a way forbidden by its access permissions

Ah got it! We are aware of this issue and are actively investigating.

Great, Thanks.

Daniel-Guenter commented 1 month ago

I am also having this issue with an HTTP trigger function after converting to .NET 8 isolated worker.

iris-masood commented 1 month ago

We are also facing the issue in Webhook after upgrading to .NET 8. Exception while executing function: Functions.message Failed to proxy request with ForwarderError: RequestBodyClient One or more errors occurred. (Sent 0 request content bytes, but Content-Length promised 4.) (An error occurred while sending the request.) Sent 0 request content bytes, but Content-Length promised 4. An error occurred while sending the request. Stream was already consumed. ` [Function("message")] public UserEventResponse AddUserToGroupOperation( [HttpTrigger(AuthorizationLevel.Function, "post")] HttpRequestData req, [WebPubSubContextInput] WebPubSubContext wpsContext) {

var request = wpsContext.Request as UserEventRequest;
var groupName = request!.Data.ToString();

// Replace the connection string and/or adjust any other settings as needed
var connectionString = Environment.GetEnvironmentVariable("WebPubSubConnectionString");
var hub = Environment.GetEnvironmentVariable("HubName");

WebPubSubServiceClient service;
if (string.IsNullOrWhiteSpace(connectionString))
{
    var hostName = Environment.GetEnvironmentVariable("PubsubHostname");
    service = new WebPubSubServiceClient(new Uri($"https://{hostName}.webpubsub.azure.com"), hub, new DefaultAzureCredential());
}
else
{
    service = new WebPubSubServiceClient(connectionString, hub);
}

service.AddUserToGroup(groupName, request.ConnectionContext.UserId);
_logger.LogInformation($"User {request.ConnectionContext.UserId} added to group {groupName}");

var response = new UserEventResponse
{
    Data = BinaryData.FromObjectAsJson(new
    { request.ConnectionContext.UserId, GroupName = groupName, ShowOnUI = false }),
    DataType = WebPubSubDataType.Json
};

_logger.LogInformation("Message event called Successfully");
return response;

} `

blakesparkes commented 1 month ago

I'm encountering the same issue after upgrading to .NET 8 Isolated Worker Process. We are getting 1 or 2 failures a day. Has anyone come up with a workaround for this?

mirokauppinen commented 1 month ago

Failed to proxy request with ForwarderError and An attempt was made to access a socket in a way forbidden by its access permissions

Ah got it! We are aware of this issue and are actively investigating.

Any findings/news about this would be appreciated. We also migrated many function apps from .NET 6 in-process to .NET8 isolated and are getting this error from time to time. Seen it pop up in premium plan also but usually it is in consumption plan functions.

duvet86 commented 4 weeks ago

Same issue here. This is NOT an upgrade though, it's a new azure function using .NET 8 isolated worker. I am using the httpclient as well, host for reference:

var host = new HostBuilder()
    .ConfigureFunctionsWebApplication()
    .ConfigureServices(services =>
    {
        services.AddApplicationInsightsTelemetryWorkerService();
        services.ConfigureFunctionsApplicationInsights();

        services.Configure<JsonSerializerOptions>(options =>
        {
            options.PropertyNamingPolicy = JsonNamingPolicy.CamelCase;
        });

        services.AddMemoryCache();

        services.AddHttpClient<IIgnitionHttpService, IgnitionHttpService>()
            .SetHandlerLifetime(TimeSpan.FromMinutes(5))
            .AddPolicyHandler((serviceProvider, _) => RetryPolicy.GetRetryPolicy(serviceProvider));
    })
    .Build();
YaseenElmaandy commented 4 weeks ago

This variation of libraries versions has reduced the issue a lot per day, but it still exists. Not sure if it helps, but here it is :

<PackageReference Include="Microsoft.Azure.Functions.Worker" Version="1.22.0" /> 

<PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.2.0" />

<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore" Version="1.3.0"/> 

<PackageReference Include="Microsoft.Azure.Functions.Worker.Sdk" Version="1.17.2" />
ErikAndreas commented 3 weeks ago

Failed to proxy request with ForwarderError and An attempt was made to access a socket in a way forbidden by its access permissions

Ah got it! We are aware of this issue and are actively investigating.

Having the same issue. Any available timelines here? At the moment consumption plan on windows is unusable because of this issue, considering v6 in-process EOL in November and more and more doing updates to/starting fresh on isolated mode any insights to timelines here would be appreciated, thanks!

mshafiqmk commented 1 week ago

I am having this issue after upgrading my function to .net core , any updates on the fix ?

mshafiqmk commented 1 week ago

I am having this issue after upgrading my function to .net core , any updates on the fix ?

Call stack

Result: Function 'MyFunctionName', Invocation id '3d1b4fb3-fb12-41a1-be7b-a58f7bf13651': An exception was thrown by the invocation. Exception: System.TimeoutException: Timed out waiting for the function start call. Invocation: '3d1b4fb3-fb12-41a1-be7b-a58f7bf13651'. ---> System.TimeoutException: The operation has timed out. at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.DefaultHttpCoordinator.SetFunctionContextAsync(String invocationId, FunctionContext context) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/Coordinator/DefaultHttpCoordinator.cs:line 56 --- End of inner exception stack trace --- at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.DefaultHttpCoordinator.SetFunctionContextAsync(String invocationId, FunctionContext context) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/Coordinator/DefaultHttpCoordinator.cs:line 67 at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.FunctionsHttpProxyingMiddleware.Invoke(FunctionContext context, FunctionExecutionDelegate next) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/FunctionsMiddleware/FunctionsHttpProxyingMiddleware.cs:line 45 at Microsoft.Azure.Functions.Worker.FunctionsApplication.InvokeFunctionAsync(FunctionContext context) in D:\a_work\1\s\src\DotNetWorker.Core\FunctionsApplication.cs:line 91 Stack: at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.DefaultHttpCoordinator.SetFunctionContextAsync(String invocationId, FunctionContext context) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/Coordinator/DefaultHttpCoordinator.cs:line 67 at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.FunctionsHttpProxyingMiddleware.Invoke(FunctionContext context, FunctionExecutionDelegate next) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/FunctionsMiddleware/FunctionsHttpProxyingMiddleware.cs:line 45 at Microsoft.Azure.Functions.Worker.FunctionsApplication.InvokeFunctionAsync(FunctionContext context) in D:\a_work\1\s\src\DotNetWorker.Core\FunctionsApplication.cs:line 91

mshafiqmk commented 1 week ago

I am having this issue after upgrading my function to .net core , any updates on the fix ?

Call stack

Result: Function 'MyFunctionName', Invocation id '3d1b4fb3-fb12-41a1-be7b-a58f7bf13651': An exception was thrown by the invocation. Exception: System.TimeoutException: Timed out waiting for the function start call. Invocation: '3d1b4fb3-fb12-41a1-be7b-a58f7bf13651'. ---> System.TimeoutException: The operation has timed out. at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.DefaultHttpCoordinator.SetFunctionContextAsync(String invocationId, FunctionContext context) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/Coordinator/DefaultHttpCoordinator.cs:line 56 --- End of inner exception stack trace --- at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.DefaultHttpCoordinator.SetFunctionContextAsync(String invocationId, FunctionContext context) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/Coordinator/DefaultHttpCoordinator.cs:line 67 at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.FunctionsHttpProxyingMiddleware.Invoke(FunctionContext context, FunctionExecutionDelegate next) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/FunctionsMiddleware/FunctionsHttpProxyingMiddleware.cs:line 45 at Microsoft.Azure.Functions.Worker.FunctionsApplication.InvokeFunctionAsync(FunctionContext context) in D:\a_work\1\s\src\DotNetWorker.Core\FunctionsApplication.cs:line 91 Stack: at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.DefaultHttpCoordinator.SetFunctionContextAsync(String invocationId, FunctionContext context) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/Coordinator/DefaultHttpCoordinator.cs:line 67 at Microsoft.Azure.Functions.Worker.Extensions.Http.AspNetCore.FunctionsHttpProxyingMiddleware.Invoke(FunctionContext context, FunctionExecutionDelegate next) in /mnt/vss/_work/1/s/extensions/Worker.Extensions.Http.AspNetCore/src/FunctionsMiddleware/FunctionsHttpProxyingMiddleware.cs:line 45 at Microsoft.Azure.Functions.Worker.FunctionsApplication.InvokeFunctionAsync(FunctionContext context) in D:\a_work\1\s\src\DotNetWorker.Core\FunctionsApplication.cs:line 91

@fabiocav @aishwaryabh

fabiocav commented 1 day ago

Additional telemetry has been added to ensure we have detailed information when the failure occurs. Will keep this open as investigation is still ongoing.