Worker Indexing - Adding log to inform about mixed function app (#8201)

surgupta-msft · web-flow · commit 1535420fc029 · 2022-03-10T10:59:58.000-08:00
* Adding logic to detect mixed app and log it

* Added tests

* Test logger string

* added tests

* Tests

* Tests refactoring

* passing scripthostoptions

* Taking scriptpath from scriptJobHostoptions

* Added list of legacy functions
diff --git a/src/WebJobs.Script/Host/AggregateFunctionMetadataProvider.cs b/src/WebJobs.Script/Host/AggregateFunctionMetadataProvider.cs
@@ -4,6 +4,7 @@
 using System;
 using System.Collections.Generic;
 using System.Collections.Immutable;
+using System.IO.Abstractions;
 using System.Linq;
 using System.Reactive.Linq;
 using System.Runtime.CompilerServices;
@@ -14,6 +15,7 @@
 using Microsoft.Azure.WebJobs.Script.Workers;
 using Microsoft.Azure.WebJobs.Script.Workers.Rpc;
 using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Options;
 using Newtonsoft.Json.Linq;
 
 namespace Microsoft.Azure.WebJobs.Script
@@ -24,16 +26,19 @@ public class AggregateFunctionMetadataProvider : IFunctionMetadataProvider
         private readonly ILogger _logger;
         private readonly IFunctionInvocationDispatcher _dispatcher;
         private ImmutableArray<FunctionMetadata> _functions;
+        private IOptions<ScriptJobHostOptions> _scriptOptions;
         private IFunctionMetadataProvider _hostFunctionMetadataProvider;
 
         public AggregateFunctionMetadataProvider(
             ILogger logger,
             IFunctionInvocationDispatcher invocationDispatcher,
-            IFunctionMetadataProvider hostFunctionMetadataProvider)
+            IFunctionMetadataProvider hostFunctionMetadataProvider,
+            IOptions<ScriptJobHostOptions> scriptOptions)
         {
             _logger = logger;
             _dispatcher = invocationDispatcher;
             _hostFunctionMetadataProvider = hostFunctionMetadataProvider;
+            _scriptOptions = scriptOptions;
         }
 
         public ImmutableDictionary<string, ImmutableArray<string>> FunctionErrors
@@ -74,6 +79,9 @@ public async Task<ImmutableArray<FunctionMetadata>> GetFunctionMetadataAsync(IEn
 
                     // set up invocation buffers and send load requests
                     await _dispatcher.FinishInitialization(functions);
+
+                    // Validate if the app has functions in legacy format and add in logs to inform about the mixed app
+                    _ = Task.Delay(TimeSpan.FromMinutes(1)).ContinueWith(t => ValidateFunctionAppFormat(_scriptOptions.Value.RootScriptPath, _logger));
                 }
                 else
                 {
@@ -85,6 +93,32 @@ public async Task<ImmutableArray<FunctionMetadata>> GetFunctionMetadataAsync(IEn
             return _functions;
         }
 
+        internal static void ValidateFunctionAppFormat(string scriptPath, ILogger logger, IFileSystem fileSystem = null)
+        {
+            fileSystem = fileSystem ?? FileUtility.Instance;
+            bool mixedApp = false;
+            string legacyFormatFunctions = null;
+
+            if (fileSystem.Directory.Exists(scriptPath))
+            {
+                var functionDirectories = fileSystem.Directory.EnumerateDirectories(scriptPath).ToImmutableArray();
+                foreach (var functionDirectory in functionDirectories)
+                {
+                    if (Utility.TryReadFunctionConfig(functionDirectory, out string json, fileSystem))
+                    {
+                        mixedApp = true;
+                        var functionName = functionDirectory.Split('\\').Last();
+                        legacyFormatFunctions = legacyFormatFunctions != null ? legacyFormatFunctions + ", " + functionName : functionName;
+                    }
+                }
+
+                if (mixedApp)
+                {
+                    logger.Log(LogLevel.Information, $"Detected mixed function app. Some functions may not be indexed - {legacyFormatFunctions}");
+                }
+            }
+        }
+
         internal IEnumerable<FunctionMetadata> ValidateMetadata(IEnumerable<RawFunctionMetadata> functions)
         {
             List<FunctionMetadata> validatedMetadata = new List<FunctionMetadata>();
diff --git a/src/WebJobs.Script/Host/FunctionMetadataManager.cs b/src/WebJobs.Script/Host/FunctionMetadataManager.cs
@@ -36,13 +36,13 @@ public class FunctionMetadataManager : IFunctionMetadataManager
         private ConcurrentDictionary<string, FunctionMetadata> _functionMetadataMap = new ConcurrentDictionary<string, FunctionMetadata>(StringComparer.OrdinalIgnoreCase);
 
         public FunctionMetadataManager(IOptions<ScriptJobHostOptions> scriptOptions, IFunctionMetadataProvider functionMetadataProvider,
-            IOptions<HttpWorkerOptions> httpWorkerOptions, IScriptHostManager scriptHostManager, ILoggerFactory loggerFactory, IOptions<LanguageWorkerOptions> languageWorkerOptions, IEnvironment environment)
+            IOptions<HttpWorkerOptions> httpWorkerOptions, IScriptHostManager scriptHostManager, ILoggerFactory loggerFactory,
+            IOptions<LanguageWorkerOptions> languageWorkerOptions, IEnvironment environment)
         {
             _scriptOptions = scriptOptions;
             _languageWorkerOptions = languageWorkerOptions;
             _serviceProvider = scriptHostManager as IServiceProvider;
             _functionMetadataProvider = functionMetadataProvider;
-
             _loggerFactory = loggerFactory;
             _logger = loggerFactory.CreateLogger(LogCategories.Startup);
             _isHttpWorker = httpWorkerOptions?.Value?.Description != null;
@@ -132,7 +132,7 @@ internal ImmutableArray<FunctionMetadata> LoadFunctionMetadata(bool forceRefresh
             ImmutableArray<FunctionMetadata> immutableFunctionMetadata;
             var workerConfigs = _languageWorkerOptions.Value.WorkerConfigs;
 
-            IFunctionMetadataProvider metadataProvider = new AggregateFunctionMetadataProvider(_loggerFactory.CreateLogger<AggregateFunctionMetadataProvider>(), dispatcher, _functionMetadataProvider);
+            IFunctionMetadataProvider metadataProvider = new AggregateFunctionMetadataProvider(_loggerFactory.CreateLogger<AggregateFunctionMetadataProvider>(), dispatcher, _functionMetadataProvider, _scriptOptions);
 
             immutableFunctionMetadata = metadataProvider.GetFunctionMetadataAsync(workerConfigs, SystemEnvironment.Instance, forceRefresh).GetAwaiter().GetResult();
 
diff --git a/test/WebJobs.Script.Tests/AggregateFunctionMetadataProviderTests.cs b/test/WebJobs.Script.Tests/AggregateFunctionMetadataProviderTests.cs
@@ -10,25 +10,28 @@
 using System.Threading.Tasks;
 using Microsoft.Azure.WebJobs.Script.Description;
 using Microsoft.Azure.WebJobs.Script.Diagnostics;
+using Microsoft.Azure.WebJobs.Script.Tests.Workers.Rpc;
 using Microsoft.Azure.WebJobs.Script.Workers;
 using Microsoft.Azure.WebJobs.Script.Workers.Rpc;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Logging.Abstractions;
+using Microsoft.Extensions.Options;
+using Microsoft.WebJobs.Script.Tests;
 using Moq;
 using Xunit;
 
 namespace Microsoft.Azure.WebJobs.Script.Tests
 {
-    public class WorkerFunctionMetadataProviderTests
+    public class AggregateFunctionMetadataProviderTests
     {
         private readonly TestLogger _logger;
         private AggregateFunctionMetadataProvider _aggregateFunctionMetadataProvider;
         private Mock<IFunctionInvocationDispatcher> _mockRpcFunctionInvocationDispatcher;
         private Mock<IFunctionMetadataProvider> _mockFunctionMetadataProvider;
 
-        public WorkerFunctionMetadataProviderTests()
+        public AggregateFunctionMetadataProviderTests()
         {
-            _logger = new TestLogger("WorkerFunctionMetadataProviderTests");
+            _logger = new TestLogger("AggregateFunctionMetadataProviderTests");
             _mockRpcFunctionInvocationDispatcher = new Mock<IFunctionInvocationDispatcher>();
             _mockFunctionMetadataProvider = new Mock<IFunctionMetadataProvider>();
         }
@@ -158,6 +161,8 @@ public void GetFunctionMetadataAsync_WorkerIndexing_HostFallback()
 
             var workerConfigs = TestHelpers.GetTestWorkerConfigs().ToImmutableArray();
             workerConfigs.ToList().ForEach(config => config.Description.WorkerIndexing = "true");
+            var scriptjobhostoptions = new ScriptJobHostOptions();
+            scriptjobhostoptions.RootScriptPath = Path.Combine(Environment.CurrentDirectory, @"..", "..", "..", "..", "..", "sample", "node");
 
             var environment = SystemEnvironment.Instance;
             environment.SetEnvironmentVariable(EnvironmentSettingNames.FunctionWorkerRuntime, "node");
@@ -168,7 +173,7 @@ public void GetFunctionMetadataAsync_WorkerIndexing_HostFallback()
             _mockRpcFunctionInvocationDispatcher.Setup(m => m.FinishInitialization(functionMetadataCollection, default)).Returns(Task.FromResult(0));
             _mockFunctionMetadataProvider.Setup(m => m.GetFunctionMetadataAsync(workerConfigs, environment, false)).Returns(Task.FromResult(functionMetadataCollection.ToImmutableArray()));
 
-            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(_logger, _mockRpcFunctionInvocationDispatcher.Object, _mockFunctionMetadataProvider.Object);
+            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(_logger, _mockRpcFunctionInvocationDispatcher.Object, _mockFunctionMetadataProvider.Object, new OptionsWrapper<ScriptJobHostOptions>(scriptjobhostoptions));
 
             // Act
             var functions = _aggregateFunctionMetadataProvider.GetFunctionMetadataAsync(workerConfigs, environment, false).GetAwaiter().GetResult();
@@ -193,13 +198,15 @@ public void GetFunctionMetadataAsync_HostIndexing()
             var workerConfigs = TestHelpers.GetTestWorkerConfigs().ToImmutableArray();
             var environment = SystemEnvironment.Instance;
             environment.SetEnvironmentVariable(EnvironmentSettingNames.FunctionWorkerRuntime, "node");
+            var scriptjobhostoptions = new ScriptJobHostOptions();
+            scriptjobhostoptions.RootScriptPath = Path.Combine(Environment.CurrentDirectory, @"..", "..", "..", "..", "..", "sample", "node");
 
             _mockRpcFunctionInvocationDispatcher.Setup(m => m.InitializeAsync(functionMetadataCollection, default)).Returns(Task.FromResult(0));
             _mockRpcFunctionInvocationDispatcher.Setup(m => m.GetWorkerMetadata()).Returns(Task.FromResult(rawFunctionMetadataCollection));
             _mockRpcFunctionInvocationDispatcher.Setup(m => m.FinishInitialization(functionMetadataCollection, default)).Returns(Task.FromResult(0));
             _mockFunctionMetadataProvider.Setup(m => m.GetFunctionMetadataAsync(workerConfigs, environment, false)).Returns(Task.FromResult(functionMetadataCollection.ToImmutableArray()));
 
-            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(_logger, _mockRpcFunctionInvocationDispatcher.Object, _mockFunctionMetadataProvider.Object);
+            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(_logger, _mockRpcFunctionInvocationDispatcher.Object, _mockFunctionMetadataProvider.Object, new OptionsWrapper<ScriptJobHostOptions>(scriptjobhostoptions));
 
             //Act
             var functions = _aggregateFunctionMetadataProvider.GetFunctionMetadataAsync(workerConfigs, environment, false).GetAwaiter().GetResult();
@@ -210,6 +217,17 @@ public void GetFunctionMetadataAsync_HostIndexing()
             Assert.False(functionLoadLogs.Any());
         }
 
+        [Fact]
+        public void ValidateFunctionAppFormat_InputMixedApp()
+        {
+            _logger.ClearLogMessages();
+            string scriptPath = Path.Combine(Environment.CurrentDirectory, @"..", "..", "..", "..", "..", "sample", "node");
+            AggregateFunctionMetadataProvider.ValidateFunctionAppFormat(scriptPath, _logger);
+            var traces = _logger.GetLogMessages();
+            var functionLoadLogs = traces.Where(m => m.FormattedMessage.Contains("Detected mixed function app. Some functions may not be indexed"));
+            Assert.True(functionLoadLogs.Any());
+        }
+
         [Fact]
         public void GetFunctionMetadataAsync_WorkerIndexing_NoHostFallback()
         {
@@ -221,6 +239,8 @@ public void GetFunctionMetadataAsync_WorkerIndexing_NoHostFallback()
 
             var workerConfigs = TestHelpers.GetTestWorkerConfigs().ToImmutableArray();
             workerConfigs.ToList().ForEach(config => config.Description.WorkerIndexing = "true");
+            var scriptjobhostoptions = new ScriptJobHostOptions();
+            scriptjobhostoptions.RootScriptPath = Path.Combine(Environment.CurrentDirectory, @"..", "..", "..", "..", "..", "sample", "node");
 
             var environment = SystemEnvironment.Instance;
             environment.SetEnvironmentVariable(EnvironmentSettingNames.FunctionWorkerRuntime, "node");
@@ -232,7 +252,7 @@ public void GetFunctionMetadataAsync_WorkerIndexing_NoHostFallback()
             _mockRpcFunctionInvocationDispatcher.Setup(m => m.FinishInitialization(functionMetadataCollection, default)).Returns(Task.FromResult(0));
             _mockFunctionMetadataProvider.Setup(m => m.GetFunctionMetadataAsync(workerConfigs, environment, false)).Returns(Task.FromResult(functionMetadataCollection.ToImmutableArray()));
 
-            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(_logger, _mockRpcFunctionInvocationDispatcher.Object, _mockFunctionMetadataProvider.Object);
+            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(_logger, _mockRpcFunctionInvocationDispatcher.Object, _mockFunctionMetadataProvider.Object, new OptionsWrapper<ScriptJobHostOptions>(scriptjobhostoptions));
 
             // Act
             var functions = _aggregateFunctionMetadataProvider.GetFunctionMetadataAsync(workerConfigs, environment, false).GetAwaiter().GetResult();
@@ -244,6 +264,47 @@ public void GetFunctionMetadataAsync_WorkerIndexing_NoHostFallback()
             Assert.True(functions.Count() == 0);
         }
 
+        [Fact]
+        public void GetFunctionMetadataAsync_InputMixedApp()
+        {
+            // Arrange
+            _logger.ClearLogMessages();
+
+            IEnumerable<RawFunctionMetadata> rawFunctionMetadataCollection = new List<RawFunctionMetadata>();
+            var functionMetadataCollection = new List<FunctionMetadata>();
+            functionMetadataCollection.Add(GetTestFunctionMetadata());
+
+            var workerConfigs = TestHelpers.GetTestWorkerConfigs().ToImmutableArray();
+            workerConfigs.ToList().ForEach(config => config.Description.WorkerIndexing = "true");
+            var scriptjobhostoptions = new ScriptJobHostOptions();
+            scriptjobhostoptions.RootScriptPath = Path.Combine(Environment.CurrentDirectory, @"..", "..", "..", "..", "..", "sample", "node");
+
+            var environment = SystemEnvironment.Instance;
+            environment.SetEnvironmentVariable(EnvironmentSettingNames.FunctionWorkerRuntime, "node");
+            environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebJobsFeatureFlags, "EnableWorkerIndexing");
+
+            _mockRpcFunctionInvocationDispatcher.Setup(m => m.InitializeAsync(functionMetadataCollection, default)).Returns(Task.FromResult(0));
+            _mockRpcFunctionInvocationDispatcher.Setup(m => m.GetWorkerMetadata()).Returns(Task.FromResult(rawFunctionMetadataCollection));
+
+            _aggregateFunctionMetadataProvider = new AggregateFunctionMetadataProvider(
+                _logger,
+                _mockRpcFunctionInvocationDispatcher.Object,
+                _mockFunctionMetadataProvider.Object,
+                new OptionsWrapper<ScriptJobHostOptions>(scriptjobhostoptions));
+
+            // Act
+            var functions = _aggregateFunctionMetadataProvider.GetFunctionMetadataAsync(workerConfigs, environment, false).GetAwaiter().GetResult();
+
+            // Assert
+            string expectedLog = "Detected mixed function app. Some functions may not be indexed";
+            var traces = _logger.GetLogMessages();
+            Assert.False(traces.Where(m => m.FormattedMessage.Contains(expectedLog)).Any());
+
+            Task.Delay(TimeSpan.FromSeconds(65)).Wait();
+            traces = _logger.GetLogMessages();
+            Assert.True(traces.Where(m => m.FormattedMessage.Contains(expectedLog)).Any());
+        }
+
         private static RawFunctionMetadata GetTestRawFunctionMetadata(bool useDefaultMetadataIndexing)
         {
             return new RawFunctionMetadata()
