public void PublishMemoryActivity_SendsRequestHeaders()
{
_metricsPublisher.Initialize();
DateTime currentTime = DateTime.UtcNow;
_metricsPublisher.AddMemoryActivity(_testMemoryActivity.EventTimeStamp, _testMemoryActivity.CommitSizeInBytes);
Assert.Empty(_testLoggerProvider.GetLog());
_metricsPublisher.OnFunctionMetricsPublishTimer(null);
_metricsPublisher.OnFunctionMetricsPublishTimer(null);
Assert.Empty(_testLoggerProvider.GetLog());
}
private async Task <LogMessage> RunTest(Action <IServiceCollection> configureWebHost = null, Action <IServiceCollection> configureJobHost = null, bool expectSuccess = true)
{
LogMessage invalidServicesMessage = null;
TestLoggerProvider loggerProvider = new TestLoggerProvider();
var builder = Program.CreateWebHostBuilder(null)
.ConfigureLogging(b =>
{
b.AddProvider(loggerProvider);
})
.ConfigureServices(s =>
{
string uniqueTestRootPath = Path.Combine(Path.GetTempPath(), "FunctionsTest", "DependencyValidatorTests");
s.PostConfigureAll <ScriptApplicationHostOptions>(o =>
{
o.IsSelfHost = true;
o.LogPath = Path.Combine(uniqueTestRootPath, "logs");
o.SecretsPath = Path.Combine(uniqueTestRootPath, "secrets");
o.ScriptPath = uniqueTestRootPath;
});
configureWebHost?.Invoke(s);
})
.ConfigureScriptHostLogging(b =>
{
b.AddProvider(loggerProvider);
})
.ConfigureScriptHostServices(b =>
{
configureJobHost?.Invoke(b);
});
using (var host = builder.Build())
{
await host.StartAsync();
await TestHelpers.Await(() =>
{
string expectedMessage = "Host initialization";
if (!expectSuccess)
{
expectedMessage = "A host error has occurred during startup operation";
}
return(loggerProvider.GetAllLogMessages()
.FirstOrDefault(p => p.FormattedMessage.StartsWith(expectedMessage)) != null);
}, userMessageCallback : () => loggerProvider.GetLog());
invalidServicesMessage = loggerProvider.GetAllLogMessages()
.FirstOrDefault(m => m.Category.EndsWith(nameof(DependencyValidator)));
await host.StopAsync();
}
return(invalidServicesMessage);
}
private async Task <LogMessage> RunTest(Action <IServiceCollection> configure = null)
{
LogMessage invalidServicesMessage = null;
TestLoggerProvider loggerProvider = new TestLoggerProvider();
var builder = Program.CreateWebHostBuilder(null)
.ConfigureLogging(b =>
{
b.AddProvider(loggerProvider);
})
.ConfigureServices(s =>
{
s.AddSingleton <IConfigureBuilder <ILoggingBuilder> >(new DelegatedConfigureBuilder <ILoggingBuilder>(b =>
{
b.AddProvider(loggerProvider);
configure?.Invoke(b.Services);
}));
string uniqueTestRootPath = Path.Combine(Path.GetTempPath(), "FunctionsTest", "DependencyValidatorTests");
s.PostConfigureAll <ScriptApplicationHostOptions>(o =>
{
o.IsSelfHost = true;
o.LogPath = Path.Combine(uniqueTestRootPath, "logs");
o.SecretsPath = Path.Combine(uniqueTestRootPath, "secrets");
o.ScriptPath = uniqueTestRootPath;
});
});
using (var host = builder.Build())
{
await host.StartAsync();
await TestHelpers.Await(() =>
{
return(loggerProvider.GetAllLogMessages()
.FirstOrDefault(p => p.FormattedMessage.StartsWith("Host initialization")) != null);
}, userMessageCallback : () => loggerProvider.GetLog());
invalidServicesMessage = loggerProvider.GetAllLogMessages()
.FirstOrDefault(m => m.Category.EndsWith(nameof(DependencyValidator)));
await host.StopAsync();
}
return(invalidServicesMessage);
}
public async Task InvocationsContainDifferentOperationIds()
{
// Verify that when a request specializes the host we don't capture the context
// of that request. Application Insights uses this context to correlate telemetry
// so it had a confusing effect. Previously all TimerTrigger traces would have the
// operation id of this request and all host logs would as well.
// Start a host in standby mode.
StandbyManager.ResetChangeToken();
string standbyPath = Path.Combine(Path.GetTempPath(), "functions", "standby", "wwwroot");
string specializedScriptRoot = @"TestScripts\CSharp";
string scriptRootConfigPath = ConfigurationPath.Combine(ConfigurationSectionNames.WebHost, nameof(ScriptApplicationHostOptions.ScriptPath));
var settings = new Dictionary <string, string>()
{
{ EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1" },
{ EnvironmentSettingNames.AzureWebsiteContainerReady, null },
};
var environment = new TestEnvironment(settings);
var loggerProvider = new TestLoggerProvider();
var channel = new TestTelemetryChannel();
var builder = Program.CreateWebHostBuilder()
.ConfigureLogging(b =>
{
b.AddProvider(loggerProvider);
})
.ConfigureAppConfiguration(c =>
{
c.AddInMemoryCollection(new Dictionary <string, string>
{
{ scriptRootConfigPath, specializedScriptRoot }
});
})
.ConfigureServices((bc, s) =>
{
s.AddSingleton <IEnvironment>(environment);
// Ensure that we don't have a race between the timer and the
// request for triggering specialization.
s.AddSingleton <IStandbyManager, InfiniteTimerStandbyManager>();
})
.AddScriptHostBuilder(webJobsBuilder =>
{
webJobsBuilder.Services.AddSingleton <ITelemetryChannel>(_ => channel);
webJobsBuilder.Services.Configure <FunctionResultAggregatorOptions>(o =>
{
o.IsEnabled = false;
});
webJobsBuilder.Services.PostConfigure <ApplicationInsightsLoggerOptions>(o =>
{
o.SamplingSettings = null;
});
webJobsBuilder.Services.PostConfigure <ScriptJobHostOptions>(o =>
{
// Only load the function we care about, but not during standby
if (o.RootScriptPath != standbyPath)
{
o.Functions = new[]
{
"OneSecondTimer",
"FunctionExecutionContext"
};
}
});
})
.ConfigureScriptHostAppConfiguration(c =>
{
c.AddInMemoryCollection(new Dictionary <string, string>
{
[EnvironmentSettingNames.AppInsightsInstrumentationKey] = "some_key"
});
});
using (var testServer = new TestServer(builder))
{
var client = testServer.CreateClient();
HttpResponseMessage response = await client.GetAsync("api/warmup");
Assert.True(response.IsSuccessStatusCode, loggerProvider.GetLog());
// Now that standby mode is warmed up, set the specialization properties...
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsiteContainerReady, "1");
environment.SetEnvironmentVariable(EnvironmentSettingNames.AzureWebsitePlaceholderMode, "0");
// ...and issue a request which will force specialization.
response = await client.GetAsync("api/functionexecutioncontext");
Assert.True(response.IsSuccessStatusCode, loggerProvider.GetLog());
// Wait until we have a few logs from the timer trigger.
IEnumerable <TraceTelemetry> timerLogs = null;
await TestHelpers.Await(() =>
{
timerLogs = channel.Telemetries
.OfType <TraceTelemetry>()
.Where(p => p.Message == "OneSecondTimer fired!");
return(timerLogs.Count() >= 3);
});
var startupRequest = channel.Telemetries
.OfType <RequestTelemetry>()
.Where(p => p.Name == "FunctionExecutionContext")
.Single();
// Make sure that auto-Http tracking worked with this request.
Assert.Equal("200", startupRequest.ResponseCode);
// The host logs should not be associated with this request.
var logsWithRequestId = channel.Telemetries
.OfType <TraceTelemetry>()
.Select(p => p.Context.Operation.Id)
.Where(p => p == startupRequest.Context.Operation.Id);
// Just expect the "Executing" and "Executed" logs from the actual request.
Assert.Equal(2, logsWithRequestId.Count());
// And each of the timer invocations should have a different operation id, and none
// should match the request id.
var distinctOpIds = timerLogs.Select(p => p.Context.Operation.Id).Distinct();
Assert.Equal(timerLogs.Count(), distinctOpIds.Count());
Assert.Empty(timerLogs.Where(p => p.Context.Operation.Id == startupRequest.Context.Operation.Id));
}
}
public async Task HostRestart_DuringInitialization_Cancels()
{
SemaphoreSlim semaphore = new SemaphoreSlim(1, 1);
await semaphore.WaitAsync();
bool waitingInHostBuilder = false;
var metricsLogger = new TestMetricsLogger();
// Have the first host start, but pause. We'll issue a restart, then
// let this first host continue and see the cancelation token has fired.
var hostA = CreateMockHost();
hostA
.Setup(h => h.StartAsync(It.IsAny <CancellationToken>()))
.Returns <CancellationToken>(async ct =>
{
waitingInHostBuilder = true;
await semaphore.WaitAsync();
ct.ThrowIfCancellationRequested();
});
var hostB = CreateMockHost();
hostB
.Setup(h => h.StartAsync(It.IsAny <CancellationToken>()))
.Returns(() => Task.CompletedTask);
var hostBuilder = new Mock <IScriptHostBuilder>();
hostBuilder.SetupSequence(b => b.BuildHost(It.IsAny <bool>(), It.IsAny <bool>()))
.Returns(hostA.Object)
.Returns(hostB.Object);
_webHostLoggerProvider = new TestLoggerProvider();
_loggerFactory = new LoggerFactory();
_loggerFactory.AddProvider(_webHostLoggerProvider);
_hostService = new WebJobsScriptHostService(
_monitor, hostBuilder.Object, _loggerFactory,
_mockScriptWebHostEnvironment.Object, _mockEnvironment.Object, _hostPerformanceManager, _healthMonitorOptions, metricsLogger, new Mock <IApplicationLifetime>().Object);
TestLoggerProvider hostALogger = hostA.Object.GetTestLoggerProvider();
Task initialStart = _hostService.StartAsync(CancellationToken.None);
Thread restartHostThread = new Thread(new ThreadStart(RestartHost));
restartHostThread.Start();
await TestHelpers.Await(() => waitingInHostBuilder);
await TestHelpers.Await(() => _webHostLoggerProvider.GetLog().Contains("Restart requested."));
// Now let the first host continue. It will see that startup is canceled.
semaphore.Release();
await TestHelpers.Await(() => _hostService.State == ScriptHostState.Running);
restartHostThread.Join();
await initialStart;
Assert.True(AreRequiredMetricsGenerated(metricsLogger));
// Make sure the error was logged to the correct logger
Assert.Contains(hostALogger.GetAllLogMessages(), m => m.FormattedMessage != null && m.FormattedMessage.StartsWith("Host startup operation '") && m.FormattedMessage.EndsWith("' was canceled."));
// Make sure we orphaned the correct host
hostA.Verify(m => m.StopAsync(It.IsAny <CancellationToken>()), Times.Exactly(1));
hostA.Verify(m => m.Dispose(), Times.Exactly(1));
// We should not be calling Orphan on the good host
hostB.Verify(m => m.StopAsync(It.IsAny <CancellationToken>()), Times.Never);
hostB.Verify(m => m.Dispose(), Times.Never);
Assert.Equal(ScriptHostState.Running, _hostService.State);
}
protected async Task VerifyWarmupSucceeds(bool restart = false)
{
string uri = "api/warmup";
if (restart)
{
uri += "?restart=1";
}
// issue warmup request and verify
var request = new HttpRequestMessage(HttpMethod.Get, uri);
var response = await _httpClient.SendAsync(request);
Assert.True(response.StatusCode == HttpStatusCode.OK, $"Expected 'OK'. Actual '{response.StatusCode}'. {_loggerProvider.GetLog()}");
string responseBody = await response.Content.ReadAsStringAsync();
Assert.Equal("WarmUp complete.", responseBody);
}
public async Task IsPlaceholderMode_ThroughoutInitialization_EvaluatesCorrectly()
{
StandbyManager.ResetChangeToken();
string standbyPath = Path.Combine(Path.GetTempPath(), "functions", "standby", "wwwroot");
string specializedScriptRoot = @"TestScripts\CSharp";
string scriptRootConfigPath = ConfigurationPath.Combine(ConfigurationSectionNames.WebHost, nameof(ScriptApplicationHostOptions.ScriptPath));
var settings = new Dictionary <string, string>()
{
{ EnvironmentSettingNames.AzureWebsitePlaceholderMode, "1" },
{ EnvironmentSettingNames.AzureWebsiteContainerReady, null },
};
var environment = new TestEnvironment(settings);
var loggerProvider = new TestLoggerProvider();
var builder = Program.CreateWebHostBuilder()
.ConfigureLogging(b =>
{
b.AddProvider(loggerProvider);
})
.ConfigureAppConfiguration(c =>
{
c.AddInMemoryCollection(new Dictionary <string, string>
{
{ scriptRootConfigPath, specializedScriptRoot }
});
})
.ConfigureServices((bc, s) =>
{
s.AddSingleton <IEnvironment>(environment);
// Simulate the environment becoming specialized after these options have been
// initialized with standby paths.
s.AddOptions <ScriptApplicationHostOptions>()
.PostConfigure <IEnvironment>((o, e) =>
{
Specialize(e);
});
})
.AddScriptHostBuilder(webJobsBuilder =>
{
webJobsBuilder.Services.PostConfigure <ScriptJobHostOptions>(o =>
{
// Only load the function we care about, but not during standby
if (o.RootScriptPath != standbyPath)
{
o.Functions = new[]
{
"HttpTrigger-Dynamic"
};
}
});
});
var server = new TestServer(builder);
var client = server.CreateClient();
// Force the specialization middleware to run
HttpResponseMessage response = await InvokeFunction(client);
response.EnsureSuccessStatusCode();
string log = loggerProvider.GetLog();
Assert.Contains("Creating StandbyMode placeholder function directory", log);
Assert.Contains("Starting host specialization", log);
// Make sure this was registered.
var hostedServices = server.Host.Services.GetServices <IHostedService>();
Assert.Contains(hostedServices, p => p is StandbyInitializationService);
}
