Deadlock in GetFunctionMetadataAsync when IFunctionMetadataProvider.GetFunctionMetadataAsync does not return

[kshyju]

The AddMetadataFromCustomProviders method gets stuck if any of the IFunctionMetadataProvider.GetFunctionMetadataAsync does not return a result.

If you look at the code, we have 2 logging statements, line 217 and 228. When the IFunctionMetadataProvider.GetFunctionMetadataAsync does not return a result, the second log statement is never executed.

azure-functions-host/src/WebJobs.Script/Host/FunctionMetadataManager.cs

Lines 217 to 230 in d1067c5

	_logger.ReadingFunctionMetadataFromProvider(_metadataProviderName);
	var functionProviderTasks = new List<Task<ImmutableArray<FunctionMetadata>>>();
	foreach (var functionProvider in functionProviders)
	{
	functionProviderTasks.Add(functionProvider.GetFunctionMetadataAsync());
	}
	var functionMetadataListArray = Task.WhenAll(functionProviderTasks).GetAwaiter().GetResult();
	// This is used to make sure no duplicates are registered
	var distinctFunctionNames = new HashSet<string>(functionMetadataList.Select(m => m.Name));
	_logger.FunctionsReturnedByProvider(functionMetadataListArray.Length, _metadataProviderName);

The issue can be reproduced by adding the below test to FunctionMetadataManagerTests.cs and run it. The test pass confirms that the log message "1 functions found (Custom)" is not produced.

[Fact]
public void FunctionMetadataManager_GetsMetadata_FromFunctionProviders_Deadlock()
{
    var functionMetadataCollection = new Collection<FunctionMetadata>();
    var mockFunctionErrors = new Dictionary<string, ImmutableArray<string>>();
    var mockFunctionMetadataProvider = new Mock<IFunctionMetadataProvider>();
    var mockFunctionProvider = new Mock<IFunctionProvider>();
    var workerConfigs = TestHelpers.GetTestWorkerConfigs();
    var testLoggerProvider = new TestLoggerProvider();
    var loggerFactory = new LoggerFactory();
    loggerFactory.AddProvider(testLoggerProvider);

    mockFunctionMetadataProvider.Setup(m => m.GetFunctionMetadataAsync(workerConfigs, SystemEnvironment.Instance, false)).Returns(Task.FromResult(new Collection<FunctionMetadata>().ToImmutableArray()));
    mockFunctionMetadataProvider.Setup(m => m.FunctionErrors).Returns(new Dictionary<string, ICollection<string>>().ToImmutableDictionary(kvp => kvp.Key, kvp => kvp.Value.ToImmutableArray()));

    functionMetadataCollection.Add(GetTestFunctionMetadata("somefile.dll", name: "anotherFunction"));

    // Mock GetFunctionMetadataAsync to never return a result.
    var tcs = new TaskCompletionSource<ImmutableArray<FunctionMetadata>>();
    mockFunctionProvider.Setup(m => m.GetFunctionMetadataAsync()).Returns(tcs.Task);

    mockFunctionProvider.Setup(m => m.FunctionErrors).Returns(mockFunctionErrors.ToImmutableDictionary());

    FunctionMetadataManager testFunctionMetadataManager = TestFunctionMetadataManager.GetFunctionMetadataManager(new OptionsWrapper<ScriptJobHostOptions>(_scriptJobHostOptions),
        mockFunctionMetadataProvider.Object, new List<IFunctionProvider>() { mockFunctionProvider.Object }, new OptionsWrapper<HttpWorkerOptions>(_defaultHttpWorkerOptions), loggerFactory, new TestOptionsMonitor<LanguageWorkerOptions>(TestHelpers.GetTestLanguageWorkerOptions()));

    // Run LoadFunctionMetadata in a separate Task to avoid blocking the test thread
    var loadFunctionMetadataTask = Task.Run(() => testFunctionMetadataManager.LoadFunctionMetadata());

    // wait 5 seconds for the task to complete
    Assert.False(loadFunctionMetadataTask.Wait(TimeSpan.FromSeconds(5)));
    var traces = testLoggerProvider.GetAllLogMessages();
    Assert.Equal(1, traces.Count(t => t.FormattedMessage.Contains("Reading functions metadata (Custom)")));
    Assert.DoesNotContain(traces, t => t.FormattedMessage.Contains("1 functions found (Custom)"));
}