public async Task StandbyModeE2E()
{
var vars = new Dictionary <string, string>
{
{ EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1" },
{ EnvironmentSettingNames.AzureWebsiteContainerReady, null },
{ EnvironmentSettingNames.AzureWebsiteSku, "Dynamic" },
{ EnvironmentSettingNames.AzureWebsiteHomePath, null },
{ "AzureWebEncryptionKey", "0F75CA46E7EBDD39E4CA6B074D1F9A5972B849A55F91A248" },
{ EnvironmentSettingNames.AzureWebsiteInstanceId, "87654639876900123453445678890144" }
};
var environment = new TestEnvironment(vars);
await InitializeTestHostAsync("Windows", environment);
await VerifyWarmupSucceeds();
await VerifyWarmupSucceeds(restart : true);
// now specialize the host
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "0");
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteContainerReady, "1");
Assert.False(environment.IsPlaceholderModeEnabled());
Assert.True(environment.IsContainerReady());
// give time for the specialization to happen
string[] logLines = null;
await TestHelpers.Await(() =>
{
// wait for the trace indicating that the host has been specialized
logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
return(logLines.Contains("Generating 0 job function(s)") && logLines.Contains("Stopping JobHost"));
}, userMessageCallback : () => string.Join(Environment.NewLine, _loggerProvider.GetAllLogMessages().Select(p => $"[{p.Timestamp.ToString("HH:mm:ss.fff")}] {p.FormattedMessage}")));
_httpServer.Dispose();
_httpClient.Dispose();
// verify the rest of the expected logs
logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
Assert.True(logLines.Count(p => p.Contains("Stopping JobHost")) >= 1);
Assert.Equal(1, logLines.Count(p => p.Contains("Creating StandbyMode placeholder function directory")));
Assert.Equal(1, logLines.Count(p => p.Contains("StandbyMode placeholder function directory created")));
Assert.Equal(2, logLines.Count(p => p.Contains("Host is in standby mode")));
Assert.Equal(2, logLines.Count(p => p.Contains("Executed 'Functions.WarmUp' (Succeeded")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting host specialization")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting language worker channel specialization")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Starting Host (HostId={_expectedHostId}")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Loading functions metadata")));
Assert.Equal(2, logLines.Count(p => p.Contains($"1 functions loaded")));
Assert.Equal(1, logLines.Count(p => p.Contains($"0 functions loaded")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Loading proxies metadata")));
Assert.Equal(1, logLines.Count(p => p.Contains("Initializing Azure Function proxies")));
Assert.Equal(1, logLines.Count(p => p.Contains($"0 proxies loaded")));
Assert.Contains("Generating 0 job function(s)", logLines);
// Verify that the internal cache has reset
Assert.NotSame(GetCachedTimeZoneInfo(), _originalTimeZoneInfoCache);
}
public async Task ZipPackageFailure_DetectedOnSpecialization()
{
_settings.Add(EnvironmentSettingNames.AzureWebsiteInstanceId, Guid.NewGuid().ToString());
var environment = new TestEnvironment(_settings);
var webHostBuilder = await CreateWebHostBuilderAsync("Windows", environment);
IWebHost host = webHostBuilder.Build();
await host.StartAsync();
Assert.True(environment.IsPlaceholderModeEnabled());
Assert.False(environment.IsContainerReady());
// after the placeholder host is fully initialized but before we specialize
// write the invalid zip marker file
string markerFilePath = Path.Combine(_expectedScriptPath, ScriptConstants.RunFromPackageFailedFileName);
File.WriteAllText(markerFilePath, "test");
// now specialize the host
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteRunFromPackage, "1");
environment.SetEnvironmentVariable(RpcWorkerConstants.FunctionWorkerRuntimeSettingName, "dotnet");
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "0");
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteContainerReady, "1");
Assert.False(environment.IsPlaceholderModeEnabled());
Assert.True(environment.IsContainerReady());
// wait for shutdown to be triggered
var applicationLifetime = host.Services.GetServices <IApplicationLifetime>().Single();
await TestHelpers.RunWithTimeoutAsync(() => applicationLifetime.ApplicationStopping.WaitHandle.WaitOneAsync(), TimeSpan.FromSeconds(30));
// ensure the host was specialized and the expected error was logged
string[] logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
Assert.True(logLines.Contains("Starting host specialization"));
Assert.True(logLines.Contains($"Shutting down host due to presence of {markerFilePath}"));
await host.StopAsync();
host.Dispose();
}
public async Task StandbyModeE2E_Dotnet()
{
_settings.Add(EnvironmentSettingNames.AzureWebsiteInstanceId, Guid.NewGuid().ToString());
var environment = new TestEnvironment(_settings);
await InitializeTestHostAsync("Windows", environment);
await VerifyWarmupSucceeds();
await VerifyWarmupSucceeds(restart : true);
// now specialize the host
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "0");
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteContainerReady, "1");
environment.SetEnvironmentVariable(RpcWorkerConstants.FunctionWorkerRuntimeSettingName, "dotnet");
Assert.False(environment.IsPlaceholderModeEnabled());
Assert.True(environment.IsContainerReady());
// give time for the specialization to happen
string[] logLines = null;
await TestHelpers.Await(() =>
{
// wait for the trace indicating that the host has been specialized
logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
return(logLines.Contains("Generating 0 job function(s)") && logLines.Contains("Stopping JobHost"));
}, userMessageCallback : () => string.Join(Environment.NewLine, _loggerProvider.GetAllLogMessages().Select(p => $"[{p.Timestamp.ToString("HH:mm:ss.fff")}] {p.FormattedMessage}")));
// verify the rest of the expected logs
logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
Assert.True(logLines.Count(p => p.Contains("Stopping JobHost")) >= 1);
Assert.Equal(1, logLines.Count(p => p.Contains("Creating StandbyMode placeholder function directory")));
Assert.Equal(1, logLines.Count(p => p.Contains("StandbyMode placeholder function directory created")));
Assert.Equal(2, logLines.Count(p => p.Contains("Host is in standby mode")));
Assert.Equal(2, logLines.Count(p => p.Contains("Executed 'Functions.WarmUp' (Succeeded")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting host specialization")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting language worker channel specialization")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Starting Host (HostId={_expectedHostId}")));
Assert.Equal(6, logLines.Count(p => p.Contains($"Loading functions metadata")));
Assert.Equal(2, logLines.Count(p => p.Contains($"1 functions loaded")));
Assert.Equal(2, logLines.Count(p => p.Contains($"0 functions loaded")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Loading proxies metadata")));
Assert.Equal(3, logLines.Count(p => p.Contains("Initializing Azure Function proxies")));
Assert.Equal(2, logLines.Count(p => p.Contains($"1 proxies loaded")));
Assert.Equal(1, logLines.Count(p => p.Contains($"0 proxies loaded")));
Assert.Contains("Generating 0 job function(s)", logLines);
// Verify that the internal cache has reset
Assert.NotSame(GetCachedTimeZoneInfo(), _originalTimeZoneInfoCache);
}
public async Task StandbyModeE2E_Java()
{
_settings.Add(EnvironmentSettingNames.AzureWebsiteInstanceId, Guid.NewGuid().ToString());
var environment = new TestEnvironment(_settings);
await InitializeTestHostAsync("Windows_Java", environment);
await VerifyWarmupSucceeds();
await VerifyWarmupSucceeds(restart : true);
// Get java process Id before specialization
IEnumerable <int> javaProcessesBefore = Process.GetProcessesByName("java").Select(p => p.Id);
// now specialize the host
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "0");
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteContainerReady, "1");
environment.SetEnvironmentVariable(LanguageWorkerConstants.FunctionWorkerRuntimeSettingName, "java");
Assert.False(environment.IsPlaceholderModeEnabled());
Assert.True(environment.IsContainerReady());
// give time for the specialization to happen
string[] logLines = null;
await TestHelpers.Await(() =>
{
// wait for the trace indicating that the host has been specialized
logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
return(logLines.Contains("Generating 0 job function(s)") && logLines.Contains("Stopping JobHost"));
}, userMessageCallback : () => string.Join(Environment.NewLine, _loggerProvider.GetAllLogMessages().Select(p => $"[{p.Timestamp.ToString("HH:mm:ss.fff")}] {p.FormattedMessage}")));
IEnumerable <int> javaProcessesAfter = Process.GetProcessesByName("java").Select(p => p.Id);
// Verify number of java processes before and after specialization are the same.
Assert.Equal(javaProcessesBefore.Count(), javaProcessesAfter.Count());
//Verify atleast one java process is running
Assert.True(javaProcessesAfter.Count() >= 1);
// Verify Java same java process is used after host restart
var result = javaProcessesBefore.Where(pId1 => !javaProcessesAfter.Any(pId2 => pId2 == pId1));
Assert.Equal(0, result.Count());
}
public async Task StandbyModeE2E_LinuxContainer()
{
byte[] bytes = TestHelpers.GenerateKeyBytes();
var encryptionKey = Convert.ToBase64String(bytes);
var containerName = "testContainer";
var vars = new Dictionary <string, string>
{
{ EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1" },
{ EnvironmentSettingNames.ContainerName, containerName },
{ EnvironmentSettingNames.AzureWebsiteHostName, "testapp.azurewebsites.net" },
{ EnvironmentSettingNames.AzureWebsiteName, "TestApp" },
{ EnvironmentSettingNames.ContainerEncryptionKey, encryptionKey },
{ EnvironmentSettingNames.AzureWebsiteContainerReady, null },
{ EnvironmentSettingNames.AzureWebsiteSku, "Dynamic" },
{ EnvironmentSettingNames.AzureWebsiteZipDeployment, null },
{ "AzureWebEncryptionKey", "0F75CA46E7EBDD39E4CA6B074D1F9A5972B849A55F91A248" }
};
var environment = new TestEnvironment(vars);
await InitializeTestHostAsync("Linux", environment);
// verify only the Warmup function is present
// generally when in placeholder mode, the list API won't be called
// but we're doing this for regression testing
var functions = await ListFunctions();
Assert.Equal(1, functions.Length);
Assert.Equal("WarmUp", functions[0]);
await VerifyWarmupSucceeds();
await VerifyWarmupSucceeds(restart : true);
// now specialize the site
await Assign(encryptionKey);
// immediately call a function - expect the call to block until
// the host is fully specialized
// the Unauthorized is expected since we havne't specified the key
// it's enough here to ensure we don't get a 404
var request = new HttpRequestMessage(HttpMethod.Get, $"api/httptrigger");
request.Headers.Add(ScriptConstants.AntaresColdStartHeaderName, "1");
var response = await _httpClient.SendAsync(request);
Assert.Equal(HttpStatusCode.Unauthorized, response.StatusCode);
// now that the host is initialized, send a valid key
// and expect success
var secretManager = _httpServer.Host.Services.GetService <ISecretManagerProvider>().Current;
var fd = _httpServer.Host.Services.GetService <IFunctionInvocationDispatcherFactory>();
var keys = await secretManager.GetFunctionSecretsAsync("HttpTrigger");
string key = keys.First().Value;
request = new HttpRequestMessage(HttpMethod.Get, $"api/httptrigger?code={key}");
request.Headers.Add(ScriptConstants.AntaresColdStartHeaderName, "1");
response = await _httpClient.SendAsync(request);
Assert.Equal(HttpStatusCode.OK, response.StatusCode);
Assert.False(environment.IsPlaceholderModeEnabled());
Assert.True(environment.IsContainerReady());
// verify that after specialization the correct
// app content is returned
functions = await ListFunctions();
Assert.Equal(1, functions.Length);
Assert.Equal("HttpTrigger", functions[0]);
// verify warmup function no longer there
request = new HttpRequestMessage(HttpMethod.Get, "api/warmup");
response = await _httpClient.SendAsync(request);
Assert.Equal(HttpStatusCode.NotFound, response.StatusCode);
string hostId = "testapp";
// verify the expected logs
var logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
Assert.True(logLines.Count(p => p.Contains("Stopping JobHost")) >= 1);
Assert.Equal(1, logLines.Count(p => p.Contains("Creating StandbyMode placeholder function directory")));
Assert.Equal(1, logLines.Count(p => p.Contains("StandbyMode placeholder function directory created")));
Assert.Equal(2, logLines.Count(p => p.Contains("Host is in standby mode")));
Assert.Equal(2, logLines.Count(p => p.Contains("Executed 'Functions.WarmUp' (Succeeded")));
Assert.Equal(1, logLines.Count(p => p.Contains("Validating host assignment context")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting Assignment")));
Assert.Equal(1, logLines.Count(p => p.Contains("Applying 3 app setting(s)")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Skipping WorkerConfig for language:python")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Skipping WorkerConfig for language:powershell")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Skipping WorkerConfig for language:java")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Extracting files to '{_expectedScriptPath}'")));
Assert.Equal(1, logLines.Count(p => p.Contains("Zip extraction complete")));
Assert.Equal(1, logLines.Count(p => p.Contains("Triggering specialization")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting host specialization")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Starting Host (HostId={hostId}")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Loading proxies metadata")));
Assert.Equal(3, logLines.Count(p => p.Contains("Initializing Azure Function proxies")));
Assert.Equal(2, logLines.Count(p => p.Contains($"1 proxies loaded")));
Assert.Equal(1, logLines.Count(p => p.Contains($"0 proxies loaded")));
Assert.Contains("Node.js HttpTrigger function invoked.", logLines);
// verify cold start log entry
var coldStartLog = _loggerProvider.GetAllLogMessages().FirstOrDefault(p => p.Category == ScriptConstants.LogCategoryHostMetrics);
JObject coldStartData = JObject.Parse(coldStartLog.FormattedMessage);
Assert.Equal("Dynamic", coldStartData["sku"]);
Assert.True((int)coldStartData["dispatchDuration"] > 0);
Assert.True((int)coldStartData["functionDuration"] > 0);
// Verify that the internal cache has reset
Assert.NotSame(GetCachedTimeZoneInfo(), _originalTimeZoneInfoCache);
}
public async Task StandbyMode_EndToEnd_LinuxContainer()
{
byte[] bytes = TestHelpers.GenerateKeyBytes();
var encryptionKey = Convert.ToBase64String(bytes);
var vars = new Dictionary <string, string>
{
{ EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1" },
{ EnvironmentSettingNames.ContainerName, "TestApp" },
{ EnvironmentSettingNames.AzureWebsiteName, "TestApp" },
{ EnvironmentSettingNames.ContainerEncryptionKey, encryptionKey },
{ EnvironmentSettingNames.AzureWebsiteContainerReady, null },
{ EnvironmentSettingNames.AzureWebsiteSku, "Dynamic" },
{ EnvironmentSettingNames.AzureWebsiteZipDeployment, null },
{ "AzureWebEncryptionKey", "0F75CA46E7EBDD39E4CA6B074D1F9A5972B849A55F91A248" }
};
var environment = new TestEnvironment(vars);
await InitializeTestHostAsync("Linux", environment);
await VerifyWarmupSucceeds();
await VerifyWarmupSucceeds(restart : true);
// now specialize the site
await Assign(encryptionKey);
// immediately call a function - expect the call to block until
// the host is fully specialized
// the Unauthorized is expected since we havne't specified the key
// it's enough here to ensure we don't get a 404
var request = new HttpRequestMessage(HttpMethod.Get, $"api/httptrigger");
request.Headers.Add(ScriptConstants.AntaresColdStartHeaderName, "1");
var response = await _httpClient.SendAsync(request);
Assert.Equal(HttpStatusCode.Unauthorized, response.StatusCode);
// now that the host is initialized, send a valid key
// and expect success
var secretManager = _httpServer.Host.Services.GetService <ISecretManagerProvider>().Current;
var keys = await secretManager.GetFunctionSecretsAsync("HttpTrigger");
string key = keys.First().Value;
request = new HttpRequestMessage(HttpMethod.Get, $"api/httptrigger?code={key}");
request.Headers.Add(ScriptConstants.AntaresColdStartHeaderName, "1");
response = await _httpClient.SendAsync(request);
Assert.Equal(HttpStatusCode.OK, response.StatusCode);
Assert.False(environment.IsPlaceholderModeEnabled());
Assert.True(environment.IsContainerReady());
// verify warmup function no longer there
request = new HttpRequestMessage(HttpMethod.Get, "api/warmup");
response = await _httpClient.SendAsync(request);
Assert.Equal(HttpStatusCode.NotFound, response.StatusCode);
_httpServer.Dispose();
_httpClient.Dispose();
// make sure there are no errors
var logs = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null);
var error = logs.Where(p => p.Level == Microsoft.Extensions.Logging.LogLevel.Error).FirstOrDefault();
Assert.True(error == null, $"Unexpected error: {error?.FormattedMessage} - {error?.Exception.ToFormattedString()}");
string sanitizedMachineName = Environment.MachineName
.Where(char.IsLetterOrDigit)
.Aggregate(new StringBuilder(), (b, c) => b.Append(c))
.ToString().ToLowerInvariant();
// verify the expected logs
var logLines = _loggerProvider.GetAllLogMessages().Where(p => p.FormattedMessage != null).Select(p => p.FormattedMessage).ToArray();
Assert.True(logLines.Count(p => p.Contains("Stopping JobHost")) >= 1);
Assert.Equal(1, logLines.Count(p => p.Contains("Creating StandbyMode placeholder function directory")));
Assert.Equal(1, logLines.Count(p => p.Contains("StandbyMode placeholder function directory created")));
Assert.Equal(2, logLines.Count(p => p.Contains("Host is in standby mode")));
Assert.Equal(2, logLines.Count(p => p.Contains("Executed 'Functions.WarmUp' (Succeeded")));
Assert.Equal(1, logLines.Count(p => p.Contains("Validating host assignment context")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting Assignment")));
Assert.Equal(1, logLines.Count(p => p.Contains("Applying 1 app setting(s)")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Extracting files to '{_expectedScriptPath}'")));
Assert.Equal(1, logLines.Count(p => p.Contains("Zip extraction complete")));
Assert.Equal(1, logLines.Count(p => p.Contains("Triggering specialization")));
Assert.Equal(1, logLines.Count(p => p.Contains("Starting host specialization")));
Assert.Equal(3, logLines.Count(p => p.Contains($"Starting Host (HostId={sanitizedMachineName}")));
Assert.Equal(1, logLines.Count(p => p.Contains($"Loading proxies metadata")));
Assert.Equal(1, logLines.Count(p => p.Contains("Initializing Azure Function proxies")));
Assert.Equal(1, logLines.Count(p => p.Contains($"0 proxies loaded")));
Assert.Contains("Node.js HttpTrigger function invoked.", logLines);
// verify cold start log entry
var coldStartLog = _loggerProvider.GetAllLogMessages().FirstOrDefault(p => p.Category == ScriptConstants.LogCategoryHostMetrics);
JObject coldStartData = JObject.Parse(coldStartLog.FormattedMessage);
Assert.Equal("Dynamic", coldStartData["sku"]);
Assert.True((int)coldStartData["dispatchDuration"] > 0);
Assert.True((int)coldStartData["functionDuration"] > 0);
// Verify that the internal cache has reset
Assert.NotSame(GetCachedTimeZoneInfo(), _originalTimeZoneInfoCache);
}
