[InlineData(LogLevel.Warning, 2, 0)] // 2x warning trace per request
public async Task QuickPulse_Works_EvenIfFiltered(LogLevel defaultLevel, int tracesPerRequest, int additionalTraces)
{
using (QuickPulseEventListener qpListener = new QuickPulseEventListener())
using (IHost host = ConfigureHost(defaultLevel))
{
ApplicationInsightsTestListener listener = new ApplicationInsightsTestListener();
int functionsCalled = 0;
bool keepRunning = true;
Task functionTask = null;
try
{
listener.StartListening();
JobHost jobHost = host.GetJobHost();
{
await host.StartAsync();
await TestHelpers.Await(() => listener.IsReady);
MethodInfo methodInfo = GetType().GetMethod(nameof(TestApplicationInsightsWarning), BindingFlags.Public | BindingFlags.Static);
// Start a task to make calls in a loop.
functionTask = Task.Run(async() =>
{
while (keepRunning)
{
await Task.Delay(100);
await jobHost.CallAsync(methodInfo);
functionsCalled++;
}
});
// Wait until we're seeing telemetry come through the QuickPulse service
double?sum = null;
await TestHelpers.Await(() =>
{
// Sum up all req/sec calls that we've received.
IEnumerable <QuickPulseMetric> reqPerSec = listener.GetQuickPulseItems()
.Select(p => p.Metrics.Where(q => q.Name == @"\ApplicationInsights\Requests/Sec").Single());
sum = reqPerSec.Sum(p => p.Value);
// All requests will go to QuickPulse.
// Just make sure we have some coming through. Choosing 5 as an arbitrary number.
return(sum >= 5);
}, timeout : 5000,
userMessageCallback : () =>
{
IEnumerable <QuickPulsePayload> items = listener.GetQuickPulseItems().OrderBy(i => i.Timestamp).Take(10);
IEnumerable <string> s = items.Select(i => $"[{i.Timestamp.ToString(_dateFormat)}] {i.Metrics.Single(p => p.Name == @"\ApplicationInsights\Requests/Sec")}");
return($"Actual QuickPulse sum: '{sum}'. DefaultLevel: '{defaultLevel}'.{Environment.NewLine}QuickPulse items ({items.Count()}): {string.Join(Environment.NewLine, s)}{Environment.NewLine}QuickPulse Logs:{qpListener.GetLog(20)}{Environment.NewLine}Logs: {host.GetTestLoggerProvider().GetLogString()}");
});
}
}
finally
{
keepRunning = false;
await functionTask;
await host.StopAsync();
listener.StopListening();
listener.Dispose();
}
string failureString = string.Join(Environment.NewLine, _channel.Telemetries.Select(t =>
{
string timestamp = $"[{t.Timestamp.ToString(_dateFormat)}] ";
switch (t)
{
case DependencyTelemetry dependency:
return(timestamp + $"[Dependency] {dependency.Name}; {dependency.Target}; {dependency.Data}");
case TraceTelemetry trace:
return(timestamp + $"[Trace] {trace.Message}");
case RequestTelemetry request:
return(timestamp + $"[Request] {request.Name}: {request.Success}");
default:
return(timestamp + $"[{t.GetType().Name}]");
}
}));
int expectedTelemetryItems = additionalTraces + (functionsCalled * tracesPerRequest);
// Filter out the odd auto-tracked request that we occassionally see from AppVeyor.
// From here: https://github.com/xunit/xunit/blob/9d10262a3694bb099ddd783d735aba2a7aac759d/src/xunit.runner.reporters/AppVeyorClient.cs#L21
var actualTelemetries = _channel.Telemetries
.Where(p => !(p is DependencyTelemetry d && d.Name == "POST /api/tests/batch"))
.ToArray();
Assert.True(actualTelemetries.Length == expectedTelemetryItems,
$"Expected: {expectedTelemetryItems}; Actual: {actualTelemetries.Length}{Environment.NewLine}{failureString}");
}
}
public async Task QuickPulse_Works_EvenIfFiltered(LogLevel defaultLevel, int expectedTelemetryItems)
{
LogCategoryFilter filter = new LogCategoryFilter();
filter.DefaultLevel = defaultLevel;
var loggerFactory = new LoggerFactory()
.AddApplicationInsights(
new TestTelemetryClientFactory(filter.Filter, _channel));
JobHostConfiguration config = new JobHostConfiguration
{
LoggerFactory = loggerFactory,
TypeLocator = new FakeTypeLocator(GetType()),
};
config.Aggregator.IsEnabled = false;
var listener = new ApplicationInsightsTestListener();
int requests = 5;
try
{
listener.StartListening();
using (JobHost host = new JobHost(config))
{
await host.StartAsync();
var methodInfo = GetType().GetMethod(nameof(TestApplicationInsightsWarning), BindingFlags.Public | BindingFlags.Static);
for (int i = 0; i < requests; i++)
{
await host.CallAsync(methodInfo);
}
await host.StopAsync();
}
}
finally
{
listener.StopListening();
}
// wait for everything to flush
await Task.Delay(2000);
// Sum up all req/sec calls that we've received.
var reqPerSec = listener
.QuickPulseItems.Select(p => p.Metrics.Where(q => q.Name == @"\ApplicationInsights\Requests/Sec").Single());
double sum = reqPerSec.Sum(p => p.Value);
// All requests will go to QuickPulse.
// The calculated RPS may off, so give some wiggle room. The important thing is that it's generating
// RequestTelemetry and not being filtered.
double max = requests + 3;
double min = requests - 2;
Assert.True(sum > min && sum < max, $"Expected sum to be greater than {min} and less than {max}. DefaultLevel: {defaultLevel}. Actual: {sum}");
// These will be filtered based on the default filter.
var infos = _channel.Telemetries.OfType <TraceTelemetry>().Where(t => t.SeverityLevel == SeverityLevel.Information);
var warns = _channel.Telemetries.OfType <TraceTelemetry>().Where(t => t.SeverityLevel == SeverityLevel.Warning);
var errs = _channel.Telemetries.OfType <TraceTelemetry>().Where(t => t.SeverityLevel == SeverityLevel.Error);
Assert.Equal(expectedTelemetryItems, _channel.Telemetries.Count());
}
