Worker startup timeout during .NET isolated metadata indexing immediately exceeds retry count instead of retrying

[brettsam]

Summary

When a .NET isolated worker process times out before sending StartStream during worker metadata indexing, the host appears to enter the normal worker restart path but immediately logs Exceeded language worker restart retry count after the first timeout. No second or third worker process start attempt is visible.

This looks like a retry-flow bug/gap: the failing channel is a webhost language worker channel created by WorkerFunctionMetadataProvider for worker indexing, but the timeout is handled by RpcFunctionInvocationDispatcher before that dispatcher has initialized its retry threshold from function metadata. As a result, ErrorEventsThreshold is still 0, so the first WorkerErrorEvent is treated as exceeding the retry limit.

Expected behavior

If a worker process starts but does not send StartStream within ProcessStartupTimeout during metadata indexing, the host should retry worker startup according to the configured retry policy, e.g. 3 * ProcessCount, or otherwise have a metadata-indexing-specific retry path.

At minimum, the first timeout should not immediately be treated as retry exhaustion.

Actual behavior

For the observed .NET isolated startup timeout, the host:

1. Started a webhost language worker channel for metadata indexing.
2. Started the worker process.
3. Timed out waiting for StartStream after ~60s.
4. Published/handled WorkerErrorEvent.
5. Logged Restarting worker channel.
6. Immediately logged Exceeded language worker restart retry count.
7. Did not start a replacement worker process.
8. The original worker sent StartStream shortly after the timeout, but it was too late to recover.

Observed evidence

Example sanitized app/worker/timeframe from production logs:

• App: <function-app>
• Stamp: <stamp>
• Role instance: <worker-role-instance>
• Time: 2026-06-09T13:22Z - 13:24Z
• Runtime: dotnet-isolated

Relevant log sequence:

Time UTC	Source	Summary
13:22:55.395	Microsoft.Azure.WebJobs.Script.WorkerFunctionMetadataProvider	Fetching metadata for workerRuntime: dotnet-isolated
13:22:55.396	Microsoft.Azure.WebJobs.Script.WorkerFunctionMetadataProvider	JobHost is starting with state 'Default'. Initializing worker channel.
13:22:55.396	Microsoft.Azure.WebJobs.Script.Workers.Rpc.WebHostRpcWorkerChannelManager	Initializing language worker channel for runtime:dotnet-isolated
13:22:55.397	Microsoft.Azure.WebJobs.Script.Workers.Rpc.WebHostRpcWorkerChannelManager	Creating language worker channel for runtime:dotnet-isolated
13:22:55.407	Microsoft.Azure.WebJobs.Script.Workers.Rpc.WebHostRpcWorkerChannelManager	Adding webhost language worker channel for runtime: dotnet-isolated. workerId:9022c7d1-161f-4ab2-a491-df0ea23f4716
13:22:55.415	Worker.LanguageWorkerChannel.dotnet-isolated.9022c7d1-161f-4ab2-a491-df0ea23f4716	Initiating Worker Process start up
13:22:57.507	Worker.rpcWorkerProcess.dotnet-isolated.9022c7d1-161f-4ab2-a491-df0ea23f4716	C:\home\site\wwwroot\<function-app>.exe process with Id=8588 started
13:23:55.830	Worker.LanguageWorkerChannel.dotnet-isolated.9022c7d1-161f-4ab2-a491-df0ea23f4716	Starting worker process failed
13:23:55.836	Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcFunctionInvocationDispatcher	Handling WorkerErrorEvent for runtime:dotnet-isolated ... System.TimeoutException
13:23:55.837	Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcFunctionInvocationDispatcher	Attempting to dispose webhost or jobhost channel for workerId: '9022c7d1-161f-4ab2-a491-df0ea23f4716', runtime: 'dotnet-isolated'
13:23:55.841	Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcFunctionInvocationDispatcher	No initialized worker channels for runtime 'dotnet-isolated'. Delaying future invocations
13:23:55.841	Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcFunctionInvocationDispatcher	Restarting worker channel for runtime: 'dotnet-isolated'
13:23:55.846	Microsoft.Azure.WebJobs.Script.Workers.Rpc.RpcFunctionInvocationDispatcher	Exceeded language worker restart retry count for runtime:dotnet-isolated. Shutting down and proactively recycling the Functions Host to recover
13:23:55.848	Microsoft.Azure.WebJobs.Script.Workers.Rpc.WebHostRpcWorkerChannelManager	Failed to start language worker process for runtime: dotnet-isolated. workerId:9022c7d1-161f-4ab2-a491-df0ea23f4716
13:23:55.852	Microsoft.Azure.WebJobs.Script.Workers.Rpc.WebHostRpcWorkerChannelManager	Failed to initialize webhost language worker channel for runtime: dotnet-isolated. workerId:9022c7d1-161f-4ab2-a491-df0ea23f4716
13:24:07.606	Worker.LanguageWorkerChannel.dotnet-isolated.9022c7d1-161f-4ab2-a491-df0ea23f4716	[channel] received 9022c7d1-161f-4ab2-a491-df0ea23f4716: StartStream

There was only one visible process start attempt for this app/worker:

Signal	Count
Initiating Worker Process start up	1
process with Id=... started	1
Starting worker process failed	1
Handling WorkerErrorEvent	1
Restarting worker channel	1
Exceeded language worker restart retry count	1
late StartStream	1

Later affected workers showed the same pattern: one process start, one startup timeout, immediate retry-exceeded log, and then a late StartStream from the original process.

Code pointers

WorkerChannel turns missing StartStream into WorkerErrorEvent

File: src/WebJobs.Script.Grpc/Channel/WorkerChannel.cs

• BeginInboundProcessing(...) registers a one-message wait for MsgType.StartStream using startStreamTimeout.
• GrpcWorkerChannel.StartWorkerProcessAsync(...) passes WorkerConfig.CountOptions.ProcessStartupTimeout.
• WorkerProcessCountOptions.ProcessStartupTimeout defaults to 60 seconds.
• On timeout, HandleWorkerStartStreamError(...) logs Starting worker process failed and publishes WorkerErrorEvent.

Relevant flow:

protected void BeginInboundProcessing(TimeSpan startStreamTimeout)
{
    RegisterCallbackForNextGrpcMessage(
        MsgType.StartStream, startStreamTimeout, count: 1,
        SendWorkerInitRequest, HandleWorkerStartStreamError);
    _ = ProcessInbound();
}

internal void HandleWorkerStartStreamError(Exception exc)
{
    _workerChannelLogger.LogError(exc, "Starting worker process failed");
    PublishWorkerErrorEvent(exc);
}

WorkerFunctionMetadataProvider starts a webhost channel before dispatcher initialization

File: src/WebJobs.Script.Grpc/WorkerFunctionMetadataProvider.cs

During worker indexing, if no channels exist and the JobHost is still starting, metadata provider initializes a webhost channel:

if (channels?.Any() != true)
{
    if (IsJobHostStarting())
    {
        _logger.LogDebug("JobHost is starting with state '{State}'. Initializing worker channel.", _scriptHostManager.State);
        await _channelManager.InitializeChannelAsync(workerConfigs, _workerRuntime);
    }
    ...
}

This is the path observed in production.

RpcFunctionInvocationDispatcher subscribes to worker errors before its threshold is initialized

File: src/WebJobs.Script.Grpc/Rpc/FunctionRegistration/RpcFunctionInvocationDispatcher.cs

The dispatcher subscribes to WorkerErrorEvent in its constructor:

_workerErrorSubscription = _eventManager.OfType<WorkerErrorEvent>().Subscribe(WorkerError);

But ErrorEventsThreshold is not assigned until InitializeAsync(...) gets function metadata:

ErrorEventsThreshold = 3 * await _maxProcessCount.Value;

During the observed metadata-indexing timeout, the dispatcher has not yet logged Worker process started and initialized., and the retry threshold appears to still be its default value 0.

Retry check immediately fails when threshold is 0

File: src/WebJobs.Script.Grpc/Rpc/FunctionRegistration/RpcFunctionInvocationDispatcher.cs

private async Task StartWorkerChannel(string runtime)
{
    ...

    if (_languageWorkerErrors.Count < ErrorEventsThreshold)
    {
        ...
        await InitializeJobhostLanguageWorkerChannelAsync(_languageWorkerErrors.Count, _workerRuntime);
        ...
    }
    else if (!_jobHostLanguageWorkerChannelManager.GetChannels().Any())
    {
        _hostMetrics.AppFailure();
        _logger.LogError("Exceeded language worker restart retry count for runtime:{runtime}. Shutting down and proactively recycling the Functions Host to recover", runtime);
        _applicationLifetime.StopApplication();
    }
}

WorkerError(...) calls AddOrUpdateErrorBucket(...) before StartWorkerChannel(...), so the first error makes _languageWorkerErrors.Count == 1. If ErrorEventsThreshold == 0, 1 < 0 is false and the host immediately goes to the Exceeded language worker restart retry count branch.

Suspected root cause

The retry code assumes ErrorEventsThreshold has already been initialized by RpcFunctionInvocationDispatcher.InitializeAsync(...). That assumption is false for worker-indexing startup failures, because the webhost metadata channel may start before the dispatcher receives function metadata and initializes its retry threshold.

There may also be a phase mismatch: StartWorkerChannel(...) retries by calling InitializeJobhostLanguageWorkerChannelAsync(...), but the failed channel in this scenario is a webhost metadata-indexing channel. At metadata-indexing time _functions may not yet be populated, so starting a jobhost invocation channel may not be the correct retry action for this failure phase.

Suggested fix direction

Potential approaches:

1. Initialize ErrorEventsThreshold earlier, e.g. in the dispatcher constructor or lazily inside WorkerError(...) / StartWorkerChannel(...), so it is never left at 0 when handling WorkerErrorEvent.
2. Separate webhost metadata-channel retry handling from jobhost invocation-channel retry handling.
3. When the errored worker belongs to WebHostRpcWorkerChannelManager, retry InitializeChannelAsync(...) through the webhost channel manager rather than InitializeJobhostLanguageWorkerChannelAsync(...).
4. Avoid logging Restarting worker channel before the threshold check, or add a clearer log when restart is skipped because the threshold has already been exceeded.

Suggested tests

Add a test that models this exact sequence:

1. Construct RpcFunctionInvocationDispatcher, which subscribes to WorkerErrorEvent.
2. Do not call InitializeAsync(...), or otherwise leave ErrorEventsThreshold in its pre-initialized state.
3. Start a webhost language worker channel for metadata indexing.
4. Simulate ProcessStartupTimeout before StartStream.
5. Assert the first timeout does not immediately call StopApplication() / log retry exceeded.
6. Assert a real retry is attempted for the metadata worker channel.

Also add a test where ErrorEventsThreshold is initialized but the failed channel is a webhost metadata channel, to verify the retry targets the correct manager/channel type.

Impact

Under worker startup pressure or noisy-neighbor conditions, a .NET isolated worker may start successfully but send StartStream slightly after the 60s timeout. If this happens during worker indexing, the host can immediately recycle after the first timeout instead of retrying. This can leave the app unhealthy and amplify a transient slow startup into an outage.

In the observed production logs, normal startup was usually fast (~7-15s), but during a burst several starts took 66-109s. The late StartStream arrived shortly after timeout, but the host had already treated the worker as failed and exhausted retries.