Skip to content

Commit 5ea0f13

Browse files
mathewcmathewc
committed
Fix proxies specialization issue (#3533)
1 parent 041fc38 commit 5ea0f13

File tree

9 files changed

+72
-53
lines changed

9 files changed

+72
-53
lines changed

‎src/WebJobs.Script.WebHost/Management/WebFunctionsManager.cs‎

Lines changed: 6 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -33,15 +33,13 @@ public class WebFunctionsManager : IWebFunctionsManager
3333
private readonly ILogger _logger;
3434
private readonly HttpClient _client;
3535
private readonly IEnumerable<WorkerConfig> _workerConfigs;
36-
private readonly IProxyMetadataManager _proxyMetadataManager;
3736

38-
public WebFunctionsManager(IOptions<ScriptApplicationHostOptions> applicationHostOptions, IOptions<LanguageWorkerOptions> languageWorkerOptions, ILoggerFactory loggerFactory, HttpClient client, IProxyMetadataManager proxyMetadataManager)
37+
public WebFunctionsManager(IOptions<ScriptApplicationHostOptions> applicationHostOptions, IOptions<LanguageWorkerOptions> languageWorkerOptions, ILoggerFactory loggerFactory, HttpClient client)
3938
{
4039
_hostOptions = applicationHostOptions.Value.ToHostOptions();
41-
_logger = loggerFactory?.CreateLogger(ScriptConstants.LogCategoryKeysController);
40+
_logger = loggerFactory?.CreateLogger(ScriptConstants.LogCategoryHostGeneral);
4241
_client = client;
4342
_workerConfigs = languageWorkerOptions.Value.WorkerConfigs;
44-
_proxyMetadataManager = proxyMetadataManager;
4543
}
4644

4745
/// <summary>
@@ -261,10 +259,11 @@ internal IEnumerable<FunctionMetadata> GetFunctionsMetadata(bool includeProxies
261259
if (includeProxies)
262260
{
263261
// get proxies metadata
264-
var proxyMetadata = _proxyMetadataManager.ProxyMetadata;
265-
if (!proxyMetadata.Functions.IsDefaultOrEmpty)
262+
var values = ProxyMetadataManager.ReadProxyMetadata(_hostOptions.RootScriptPath, _logger);
263+
var proxyFunctionsMetadata = values.Item1;
264+
if (proxyFunctionsMetadata?.Count > 0)
266265
{
267-
functionsMetadata = proxyMetadata.Functions.Concat(functionsMetadata);
266+
functionsMetadata = proxyFunctionsMetadata.Concat(functionsMetadata);
268267
}
269268
}
270269

‎src/WebJobs.Script/Environment/EnvironmentSettingNames.cs‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,6 @@ public static class EnvironmentSettingNames
2121
public const string AzureWebsiteAppCountersName = "WEBSITE_COUNTERS_APP";
2222
public const string AzureWebJobsSecretStorageType = "AzureWebJobsSecretStorageType";
2323
public const string AppInsightsInstrumentationKey = "APPINSIGHTS_INSTRUMENTATIONKEY";
24-
public const string ProxySiteExtensionEnabledKey = "ROUTING_EXTENSION_VERSION";
2524
public const string FunctionsExtensionVersion = "FUNCTIONS_EXTENSION_VERSION";
2625
public const string ContainerName = "CONTAINER_NAME";
2726
public const string WebSiteAuthEncryptionKey = "WEBSITE_AUTH_ENCRYPTION_KEY";

‎src/WebJobs.Script/Host/FunctionMetadataManager.cs‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,9 @@ public ImmutableDictionary<string, ImmutableArray<string>> Errors
4545
/// </summary>
4646
private ImmutableArray<FunctionMetadata> LoadFunctionMetadata()
4747
{
48+
_logger.LogInformation("Loading functions metadata");
4849
Collection<FunctionMetadata> functionMetadata = ReadFunctionsMetadata();
50+
_logger.LogInformation($"{functionMetadata.Count} functions loaded");
4951

5052
return functionMetadata.ToImmutableArray();
5153
}

‎src/WebJobs.Script/Host/ProxyMetadataManager.cs‎

Lines changed: 14 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -24,16 +24,16 @@ public class ProxyMetadataManager : IProxyMetadataManager, IDisposable
2424
{
2525
private static readonly Regex ProxyNameValidationRegex = new Regex(@"[^a-zA-Z0-9_-]", RegexOptions.Compiled | RegexOptions.IgnoreCase);
2626
private readonly ReaderWriterLockSlim _metadataLock = new ReaderWriterLockSlim();
27-
private readonly IOptionsMonitor<ScriptApplicationHostOptions> _applicationHostOptions;
27+
private readonly IOptions<ScriptJobHostOptions> _scriptOptions;
2828
private readonly IEnvironment _environment;
2929
private readonly ILogger _logger;
3030
private readonly IDisposable _fileChangeSubscription;
3131
private Lazy<ProxyMetadataInfo> _metadata;
3232
private bool _disposed = false;
3333

34-
public ProxyMetadataManager(IOptionsMonitor<ScriptApplicationHostOptions> applicationHostOptions, IEnvironment environment, IScriptEventManager eventManager, ILoggerFactory loggerFactory)
34+
public ProxyMetadataManager(IOptions<ScriptJobHostOptions> scriptOptions, IEnvironment environment, IScriptEventManager eventManager, ILoggerFactory loggerFactory)
3535
{
36-
_applicationHostOptions = applicationHostOptions;
36+
_scriptOptions = scriptOptions;
3737
_environment = environment;
3838
_logger = loggerFactory.CreateLogger(LogCategories.Startup);
3939
_metadata = new Lazy<ProxyMetadataInfo>(LoadFunctionMetadata);
@@ -79,7 +79,7 @@ private void HandleProxyFileChange()
7979
private ProxyMetadataInfo LoadFunctionMetadata()
8080
{
8181
var functionErrors = new Dictionary<string, ICollection<string>>();
82-
(Collection<FunctionMetadata> proxies, ProxyClientExecutor client) = ReadProxyMetadata(functionErrors);
82+
(Collection<FunctionMetadata> proxies, ProxyClientExecutor client) = ReadProxyMetadata(_scriptOptions.Value.RootScriptPath, _logger, functionErrors);
8383

8484
ImmutableArray<FunctionMetadata> metadata;
8585
if (proxies != null && proxies.Any())
@@ -91,39 +91,35 @@ private ProxyMetadataInfo LoadFunctionMetadata()
9191
return new ProxyMetadataInfo(metadata, errors, client);
9292
}
9393

94-
internal (Collection<FunctionMetadata>, ProxyClientExecutor) ReadProxyMetadata(Dictionary<string, ICollection<string>> functionErrors)
94+
internal static (Collection<FunctionMetadata>, ProxyClientExecutor) ReadProxyMetadata(string scriptPath, ILogger logger, Dictionary<string, ICollection<string>> functionErrors = null)
9595
{
96+
functionErrors = functionErrors ?? new Dictionary<string, ICollection<string>>();
97+
9698
// read the proxy config
97-
string proxyConfigPath = Path.Combine(_applicationHostOptions.CurrentValue.ScriptPath, ScriptConstants.ProxyMetadataFileName);
99+
string proxyConfigPath = Path.Combine(scriptPath, ScriptConstants.ProxyMetadataFileName);
98100
if (!File.Exists(proxyConfigPath))
99101
{
100102
return (null, null);
101103
}
102104

103-
var proxyAppSettingValue = _environment.GetEnvironmentVariable(EnvironmentSettingNames.ProxySiteExtensionEnabledKey);
104-
105-
// This is for backward compatibility only, if the file is present but the value of proxy app setting(ROUTING_EXTENSION_VERSION) is explicitly set to 'disabled' we will ignore loading the proxies.
106-
if (!string.IsNullOrWhiteSpace(proxyAppSettingValue) && proxyAppSettingValue.Equals("disabled", StringComparison.OrdinalIgnoreCase))
107-
{
108-
return (null, null);
109-
}
110-
111105
string proxiesJson = File.ReadAllText(proxyConfigPath);
112-
113106
if (!string.IsNullOrWhiteSpace(proxiesJson))
114107
{
115-
return LoadProxyMetadata(proxiesJson, functionErrors);
108+
logger.LogInformation("Loading proxies metadata");
109+
var values = LoadProxyMetadata(proxiesJson, functionErrors, logger);
110+
logger.LogInformation($"{values.Item1.Count} proxies loaded");
111+
return values;
116112
}
117113

118114
return (null, null);
119115
}
120116

121-
private (Collection<FunctionMetadata>, ProxyClientExecutor) LoadProxyMetadata(string proxiesJson, Dictionary<string, ICollection<string>> functionErrors)
117+
private static (Collection<FunctionMetadata>, ProxyClientExecutor) LoadProxyMetadata(string proxiesJson, Dictionary<string, ICollection<string>> functionErrors, ILogger logger)
122118
{
123119
var proxies = new Collection<FunctionMetadata>();
124120
ProxyClientExecutor client = null;
125121

126-
var rawProxyClient = ProxyClientFactory.Create(proxiesJson, _logger);
122+
var rawProxyClient = ProxyClientFactory.Create(proxiesJson, logger);
127123
if (rawProxyClient != null)
128124
{
129125
client = new ProxyClientExecutor(rawProxyClient);

‎src/WebJobs.Script/ScriptHostBuilderExtensions.cs‎

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -106,14 +106,16 @@ public static IHostBuilder AddScriptHostCore(this IHostBuilder builder, ScriptAp
106106
configureWebJobs?.Invoke(webJobsBuilder);
107107
}, o => o.AllowPartialHostStartup = true);
108108

109-
// Script host services
109+
// Script host services - these services are scoped to a host instance, and when a new host
110+
// is created, these services are recreated
110111
builder.ConfigureServices(services =>
111112
{
112113
// Core WebJobs/Script Host services
113114
services.AddSingleton<ScriptHost>();
114115
services.AddSingleton<IScriptJobHost>(p => p.GetRequiredService<ScriptHost>());
115116
services.AddSingleton<IJobHost>(p => p.GetRequiredService<ScriptHost>());
116117
services.AddSingleton<IFunctionMetadataManager, FunctionMetadataManager>();
118+
services.AddSingleton<IProxyMetadataManager, ProxyMetadataManager>();
117119
services.AddSingleton<ITypeLocator, ScriptTypeLocator>();
118120
services.AddSingleton<ScriptSettingsManager>();
119121
services.AddTransient<IExtensionsManager, ExtensionsManager>();
@@ -157,12 +159,16 @@ public static IHostBuilder AddScriptHostCore(this IHostBuilder builder, ScriptAp
157159

158160
public static void AddCommonServices(IServiceCollection services)
159161
{
162+
// The scope for these services is beyond a single host instance.
163+
// They are not recreated for each new host instance, so you have
164+
// to be careful with caching, etc. E.g. these services will get
165+
// initially created in placeholder mode and live on through the
166+
// specialized app.
160167
services.AddSingleton<IHostIdProvider, ScriptHostIdProvider>();
161168
services.TryAddSingleton<IScriptEventManager, ScriptEventManager>();
162169
services.TryAddSingleton<IDebugManager, DebugManager>();
163170
services.TryAddSingleton<IDebugStateProvider, DebugStateProvider>();
164171
services.TryAddSingleton<IEnvironment>(SystemEnvironment.Instance);
165-
services.AddSingleton<IProxyMetadataManager, ProxyMetadataManager>();
166172
services.TryAddSingleton<HostPerformanceManager>();
167173
services.ConfigureOptions<HostHealthMonitorOptionsSetup>();
168174
}

‎test/WebJobs.Script.Tests.Integration/ApplicationInsights/ApplicationInsightsEndToEndTestsBase.cs‎

Lines changed: 13 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -228,7 +228,7 @@ public async Task Validate_HostLogs()
228228
// slightly out-of-order or on different threads
229229
TraceTelemetry[] traces = null;
230230

231-
int expectedCount = 10;
231+
int expectedCount = 12;
232232

233233
await TestHelpers.Await(() =>
234234
{
@@ -253,16 +253,18 @@ await TestHelpers.Await(() =>
253253

254254
Assert.True(traces.Length == expectedCount, $"Expected {expectedCount} messages, but found {traces.Length}. Actual logs:{Environment.NewLine}{string.Join(Environment.NewLine, traces.Select(t => t.Message))}");
255255

256-
ValidateTrace(traces[0], "A function whitelist has been specified", LogCategories.Startup);
257-
ValidateTrace(traces[1], "Found the following functions:\r\n", LogCategories.Startup);
258-
ValidateTrace(traces[2], "Generating 2 job function(s)", LogCategories.Startup);
259-
ValidateTrace(traces[3], "Host initialization: ConsecutiveErrors=0, StartupCount=1", LogCategories.Startup);
260-
ValidateTrace(traces[4], "Host initialized (", LogCategories.Startup);
261-
ValidateTrace(traces[5], "Host lock lease acquired by instance ID", ScriptConstants.LogCategoryHostGeneral);
262-
ValidateTrace(traces[6], "Host started (", LogCategories.Startup);
263-
ValidateTrace(traces[7], "Initializing Host", LogCategories.Startup);
264-
ValidateTrace(traces[8], "Job host started", LogCategories.Startup);
265-
ValidateTrace(traces[9], "Starting Host (HostId=", LogCategories.Startup);
256+
ValidateTrace(traces[0], "2 functions loaded", LogCategories.Startup);
257+
ValidateTrace(traces[1], "A function whitelist has been specified", LogCategories.Startup);
258+
ValidateTrace(traces[2], "Found the following functions:\r\n", LogCategories.Startup);
259+
ValidateTrace(traces[3], "Generating 2 job function(s)", LogCategories.Startup);
260+
ValidateTrace(traces[4], "Host initialization: ConsecutiveErrors=0, StartupCount=1", LogCategories.Startup);
261+
ValidateTrace(traces[5], "Host initialized (", LogCategories.Startup);
262+
ValidateTrace(traces[6], "Host lock lease acquired by instance ID", ScriptConstants.LogCategoryHostGeneral);
263+
ValidateTrace(traces[7], "Host started (", LogCategories.Startup);
264+
ValidateTrace(traces[8], "Initializing Host", LogCategories.Startup);
265+
ValidateTrace(traces[9], "Job host started", LogCategories.Startup);
266+
ValidateTrace(traces[10], "Loading functions metadata", LogCategories.Startup);
267+
ValidateTrace(traces[11], "Starting Host (HostId=", LogCategories.Startup);
266268
}
267269

268270
[Fact]

‎test/WebJobs.Script.Tests.Integration/Host/StandbyManagerTests.cs‎

Lines changed: 23 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -91,13 +91,20 @@ await TestHelpers.Await(() =>
9191
_httpClient.Dispose();
9292

9393
// verify the rest of the expected logs
94+
logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
9495
Assert.True(logLines.Count(p => p.Contains("Stopping JobHost")) >= 1);
9596
Assert.Equal(1, logLines.Count(p => p.Contains("Creating StandbyMode placeholder function directory")));
9697
Assert.Equal(1, logLines.Count(p => p.Contains("StandbyMode placeholder function directory created")));
9798
Assert.Equal(2, logLines.Count(p => p.Contains("Host is in standby mode")));
9899
Assert.Equal(2, logLines.Count(p => p.Contains("Executed 'Functions.WarmUp' (Succeeded")));
99100
Assert.Equal(1, logLines.Count(p => p.Contains("Starting host specialization")));
100101
Assert.Equal(3, logLines.Count(p => p.Contains($"Starting Host (HostId={_expectedHostId}")));
102+
Assert.Equal(3, logLines.Count(p => p.Contains($"Loading functions metadata")));
103+
Assert.Equal(2, logLines.Count(p => p.Contains($"1 functions loaded")));
104+
Assert.Equal(1, logLines.Count(p => p.Contains($"0 functions loaded")));
105+
Assert.Equal(1, logLines.Count(p => p.Contains($"Loading proxies metadata")));
106+
Assert.Equal(1, logLines.Count(p => p.Contains("Initializing Azure Function proxies")));
107+
Assert.Equal(1, logLines.Count(p => p.Contains($"0 proxies loaded")));
101108
Assert.Contains("Generating 0 job function(s)", logLines);
102109

103110
// Verify that the internal cache has reset
@@ -162,6 +169,11 @@ public async Task StandbyMode_EndToEnd_LinuxContainer()
162169
_httpServer.Dispose();
163170
_httpClient.Dispose();
164171

172+
// make sure there are no errors
173+
var logs = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null);
174+
var error = logs.Where(p => p.Level == Microsoft.Extensions.Logging.LogLevel.Error).FirstOrDefault();
175+
Assert.True(error == null, $"Unexpected error: {error?.FormattedMessage} - {error?.Exception.ToFormattedString()}");
176+
165177
string sanitizedMachineName = Environment.MachineName
166178
.Where(char.IsLetterOrDigit)
167179
.Aggregate(new StringBuilder(), (b, c) => b.Append(c))
@@ -182,6 +194,9 @@ public async Task StandbyMode_EndToEnd_LinuxContainer()
182194
Assert.Equal(1, logLines.Count(p => p.Contains("Triggering specialization")));
183195
Assert.Equal(1, logLines.Count(p => p.Contains("Starting host specialization")));
184196
Assert.Equal(3, logLines.Count(p => p.Contains($"Starting Host (HostId={sanitizedMachineName}")));
197+
Assert.Equal(1, logLines.Count(p => p.Contains($"Loading proxies metadata")));
198+
Assert.Equal(1, logLines.Count(p => p.Contains("Initializing Azure Function proxies")));
199+
Assert.Equal(1, logLines.Count(p => p.Contains($"0 proxies loaded")));
185200
Assert.Contains("Node.js HttpTrigger function invoked.", logLines);
186201

187202
// verify cold start log entry
@@ -199,6 +214,12 @@ private async Task InitializeTestHostAsync(string testDirName, IEnvironment envi
199214
{
200215
var httpConfig = new HttpConfiguration();
201216
var uniqueTestRootPath = Path.Combine(_testRootPath, testDirName, Guid.NewGuid().ToString());
217+
var scriptRootPath = Path.Combine(uniqueTestRootPath, "wwwroot");
218+
219+
FileUtility.EnsureDirectoryExists(scriptRootPath);
220+
string proxyConfigPath = Path.Combine(scriptRootPath, "proxies.json");
221+
File.WriteAllText(proxyConfigPath, "{}");
222+
await TestHelpers.Await(() => File.Exists(proxyConfigPath));
202223

203224
_loggerProvider = new TestLoggerProvider();
204225

@@ -232,11 +253,10 @@ private async Task InitializeTestHostAsync(string testDirName, IEnvironment envi
232253
o.IsSelfHost = true;
233254
o.LogPath = Path.Combine(uniqueTestRootPath, "logs");
234255
o.SecretsPath = Path.Combine(uniqueTestRootPath, "secrets");
235-
o.ScriptPath = _expectedScriptPath = Path.Combine(uniqueTestRootPath, "wwwroot");
256+
o.ScriptPath = _expectedScriptPath = scriptRootPath;
236257
});
237258

238259
c.AddSingleton<IEnvironment>(_ => environment);
239-
240260
c.AddSingleton<IConfigureBuilder<ILoggingBuilder>>(new DelegatedConfigureBuilder<ILoggingBuilder>(b => b.AddProvider(_loggerProvider)));
241261
});
242262

@@ -353,7 +373,7 @@ private void CleanupTestDirectory()
353373
var testRootPath = Path.Combine(Path.GetTempPath(), "StandbyManagerTests");
354374
try
355375
{
356-
FileUtility.DeleteDirectoryAsync(testRootPath, true);
376+
FileUtility.DeleteDirectoryAsync(testRootPath, true).GetAwaiter().GetResult();
357377
}
358378
catch
359379
{

0 commit comments

Comments
 (0)