azure-functions-host icon indicating copy to clipboard operation
azure-functions-host copied to clipboard

Flex Consumption timer functions are killed

Open konrad11901 opened this issue 4 months ago • 2 comments

Investigative information

Please provide the following:

  • Timestamp: 2024-10-16T10:00:00.0021088Z
  • Function App version: 4
  • Function App name: flexconsumptiontimer-test-func
  • Function name(s) (as appropriate): TimerFunction
  • Invocation ID: c2c3130e-7709-4710-af5c-ee2b4c024f95
  • Region: northeurope

Repro steps

  1. Create a simple timer-triggered C# function like this:
Function source code
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.Logging;

namespace FlexConsumptionTimer
{
    public class TimerFunction
    {
        private readonly ILogger _logger;

        public TimerFunction(ILoggerFactory loggerFactory)
        {
            _logger = loggerFactory.CreateLogger<TimerFunction>();
        }

        [Function("TimerFunction")]
        public async Task Run([TimerTrigger("0 0 10 * * *")] TimerInfo myTimer, CancellationToken cancellationToken)
        {
            _logger.LogInformation("C# Timer trigger function executed at: {time}", DateTime.Now);

            // Register a callback to log when the function is cancelled
            // so that we can track if Functions worker is cancelling the function
            using var reg = cancellationToken.Register(() =>
            {
                _logger.LogWarning(
                    "Someone (user or Azure Functions host) requested to cancel the job! Trace: {trace}",
                    Environment.StackTrace);
            });

            await Task.Delay(1000 * 60 * 5, cancellationToken); // Wait for 5 minutes

            if (myTimer.ScheduleStatus is not null)
            {
                _logger.LogInformation("Next timer schedule at: {time}", myTimer.ScheduleStatus.Next);
            }
        }
    }
}
Program.cs
using Microsoft.Azure.Functions.Worker;
using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Hosting;

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

host.Run();
Package references
<PackageReference Include="Microsoft.Azure.Functions.Worker" Version="1.23.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.2" />
<PackageReference Include="Microsoft.Azure.Functions.Worker.Extensions.Timer" Version="4.3.1" />
<PackageReference Include="Microsoft.Azure.Functions.Worker.Sdk" Version="1.18.1" />
<PackageReference Include="Microsoft.ApplicationInsights.WorkerService" Version="2.22.0" />
<PackageReference Include="Microsoft.Azure.Functions.Worker.ApplicationInsights" Version="1.4.0" />
  1. Create a new Azure Functions instance and necessary dependencies:
az group create --name "<RG name>" --location "northeurope"
az storage account create --name "<Storage Account name>" --location "northeurope" --resource-group "<RG name>" --sku Standard_LRS --allow-blob-public-access false --https-only
az functionapp create --resource-group "<RG name>" --name "flexconsumptiontimer-test-func" --storage-account "<Storage Account name>" --flexconsumption-location "northeurope" --runtime dotnet-isolated --runtime-version 8.0
  1. Deploy the previously created function:
func azure functionapp publish flexconsumptiontimer-test-func

Expected behavior

Function execution finishes successfully.

Actual behavior

Function execution is being killed by the host within a minute of starting the function.
It looks like there is some scaling down involved (that's my guess based on DrainMode mention in logs), which kills the ongoing execution of the function?

Known workarounds

Manual rerun of the function seems to work.

Related information

We had this issue earlier too (back in August) - then a simple package update seemed to help as the functions were working fine till the beginning of October.

This issue is not occurring on the Consumption plan.

Programming language used: C# Bindings used: Timer

Logs
10/16/2024, 10:00:00.002 AM Executing 'Functions.TimerFunction' (Reason='Timer fired at 2024-10-16T09:59:59.9998519+00:00', Id=c2c3130e-7709-4710-af5c-ee2b4c024f95)
10/16/2024, 10:00:25.346 AM DrainMode mode enabled
10/16/2024, 10:00:25.346 AM Calling StopAsync on the registered listeners
10/16/2024, 10:00:25.347 AM Stopping the listener 'Microsoft.Azure.WebJobs.Host.Listeners.SingletonListener' for function 'TimerFunction'
10/16/2024, 10:00:25.356 AM Someone (user or Azure Functions host) requested to cancel the job! Trace: at System.Environment.get_StackTrace() at FlexConsumptionTimer.TimerFunction.<Run>b__2_0() in <...>\FlexConsumptionTimer\TimerFunction.cs:line 24 at System.Threading.CancellationTokenSource.Invoke(Delegate d, Object state, CancellationTokenSource source) at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state) at System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean throwOnFirstException) at Microsoft.Azure.Functions.Worker.Handlers.InvocationHandler.TryCancel(String invocationId) in D:\a\_work\1\s\src\DotNetWorker.Grpc\Handlers\InvocationHandler.cs:line 147 at Microsoft.Azure.Functions.Worker.GrpcWorker.InvocationCancelRequestHandler(InvocationCancel request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\GrpcWorker.cs:line 127 at Microsoft.Azure.Functions.Worker.GrpcWorker.ProcessRequestCoreAsync(StreamingMessage request) in D:\a\_work\1\s\src\DotNetWorker.Grpc\GrpcWorker.cs:line 109 at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[TStateMachine](TStateMachine& stateMachine) at Microsoft.Azure.Functions.Worker.GrpcWorker.ProcessRequestCoreAsync(StreamingMessage request) at Microsoft.Azure.Functions.Worker.GrpcWorker.<>c__DisplayClass11_0.<Microsoft.Azure.Functions.Worker.Grpc.IMessageProcessor.ProcessMessageAsync>b__0() in D:\a\_work\1\s\src\DotNetWorker.Grpc\GrpcWorker.cs:line 66 at System.Threading.Tasks.Task`1.InnerInvoke() at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(Thread threadPoolThread, ExecutionContext executionContext, ContextCallback callback, Object state) at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread) at System.Threading.ThreadPoolWorkQueue.Dispatch() at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
10/16/2024, 10:00:25.380 AM Executed 'Functions.TimerFunction' (Failed, Id=c2c3130e-7709-4710-af5c-ee2b4c024f95, Duration=25380ms)
10/16/2024, 10:00:25.414 AM Stopped the listener 'Microsoft.Azure.WebJobs.Host.Listeners.SingletonListener' for function 'TimerFunction'
10/16/2024, 10:00:25.415 AM Call to StopAsync complete, registered listeners are now stopped

konrad11901 avatar Oct 16 '24 10:10 konrad11901