public async Task RouteAsync_FailOnNoAction_LogsCorrectValues()
{
// Arrange
var sink = new TestSink();
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
var mockActionSelector = new Mock<IActionSelector>();
mockActionSelector
.Setup(a => a.Select(It.IsAny<RouteContext>()))
.Returns<ActionDescriptor>(null);
var context = CreateRouteContext(
actionSelector: mockActionSelector.Object,
loggerFactory: loggerFactory);
var handler = new MvcRouteHandler();
var expectedMessage = "No actions matched the current request";
// Act
await handler.RouteAsync(context);
// Assert
Assert.Empty(sink.Scopes);
Assert.Single(sink.Writes);
Assert.Equal(expectedMessage, sink.Writes[0].State?.ToString());
}
public async void SelectAsync_AmbiguousActions_LogIsCorrect()
{
// Arrange
var sink = new TestSink();
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
var actions = new ActionDescriptor[]
{
new ActionDescriptor() { DisplayName = "A1" },
new ActionDescriptor() { DisplayName = "A2" },
};
var selector = CreateSelector(actions, loggerFactory);
var routeContext = CreateRouteContext("POST");
var actionNames = string.Join(Environment.NewLine, actions.Select(action => action.DisplayName));
var expectedMessage = "Request matched multiple actions resulting in " +
$"ambiguity. Matching actions: {actionNames}";
// Act
await Assert.ThrowsAsync<AmbiguousActionException>(async () =>
{
await selector.SelectAsync(routeContext);
});
// Assert
Assert.Empty(sink.Scopes);
Assert.Single(sink.Writes);
Assert.Equal(expectedMessage, sink.Writes[0].State?.ToString());
}
public async Task RouteHandler_Success_LogsCorrectValues()
{
// Arrange
var sink = new TestSink();
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
var displayName = "A.B.C";
var actionDescriptor = new Mock<ActionDescriptor>();
actionDescriptor
.SetupGet(ad => ad.DisplayName)
.Returns(displayName);
var context = CreateRouteContext(actionDescriptor: actionDescriptor.Object, loggerFactory: loggerFactory);
var handler = new MvcRouteHandler();
await handler.RouteAsync(context);
// Act
await context.Handler(context.HttpContext);
// Assert
Assert.Single(sink.Scopes);
Assert.Equal(displayName, sink.Scopes[0].Scope?.ToString());
Assert.Equal(2, sink.Writes.Count);
Assert.Equal($"Executing action {displayName}", sink.Writes[0].State?.ToString());
// This message has the execution time embedded, which we don't want to verify.
Assert.StartsWith($"Executed action {displayName} ", sink.Writes[1].State?.ToString());
}
public async void Invoke_DoesNotLog_WhenHandled()
{
// Arrange
var isHandled = true;
var sink = new TestSink(
TestSink.EnableWithTypeName<RouterMiddleware>,
TestSink.EnableWithTypeName<RouterMiddleware>);
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
var httpContext = new DefaultHttpContext();
httpContext.RequestServices = new ServiceProvider();
RequestDelegate next = (c) =>
{
return Task.FromResult<object>(null);
};
var router = new TestRouter(isHandled);
var middleware = new RouterMiddleware(next, loggerFactory, router);
// Act
await middleware.Invoke(httpContext);
// Assert
Assert.Empty(sink.Scopes);
Assert.Empty(sink.Writes);
}
public async void Invoke_LogsCorrectValues_WhenNotHandled()
{
// Arrange
var expectedMessage = "Request did not match any routes.";
var isHandled = false;
var sink = new TestSink(
TestSink.EnableWithTypeName<RouterMiddleware>,
TestSink.EnableWithTypeName<RouterMiddleware>);
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
var httpContext = new DefaultHttpContext();
httpContext.RequestServices = new ServiceProvider();
RequestDelegate next = (c) =>
{
return Task.FromResult<object>(null);
};
var router = new TestRouter(isHandled);
var middleware = new RouterMiddleware(next, loggerFactory, router);
// Act
await middleware.Invoke(httpContext);
// Assert
Assert.Empty(sink.Scopes);
Assert.Single(sink.Writes);
Assert.Equal(expectedMessage, sink.Writes[0].State?.ToString());
}
private async Task<Tuple<TestSink, RouteContext>> SetUp(
bool loggerEnabled,
string routeName,
string template,
string requestPath,
TestSink testSink = null)
{
if (testSink == null)
{
testSink = new TestSink(
TestSink.EnableWithTypeName<TemplateRoute>,
TestSink.EnableWithTypeName<TemplateRoute>);
}
var loggerFactory = new TestLoggerFactory(testSink, loggerEnabled);
TemplateRoute route;
if (!string.IsNullOrEmpty(routeName))
{
route = CreateRoute(routeName, template);
}
else
{
route = CreateRoute(template);
}
var context = CreateRouteContext(requestPath, loggerFactory);
// Act
await route.RouteAsync(context);
return Tuple.Create(testSink, context);
}
public TestLogger(TestLoggerFactory factory)
{
_logger = factory.CreateLogger <T>();
}
private static async Task<TestSink> SetUp(bool enabled, bool handled)
{
// Arrange
var sink = new TestSink(
TestSink.EnableWithTypeName<RouteCollection>,
TestSink.EnableWithTypeName<RouteCollection>);
var loggerFactory = new TestLoggerFactory(sink, enabled);
var routes = new RouteCollection();
var route = CreateRoute(accept: handled);
routes.Add(route.Object);
var context = CreateRouteContext("/Cool", loggerFactory);
// Act
await routes.RouteAsync(context);
return sink;
}
public async Task ExpiredSession_LogsWarning()
{
var sink = new TestSink();
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
using (var server = TestServer.Create(app =>
{
app.UseSession();
app.Run(context =>
{
int? value = context.Session.GetInt32("Key");
if (context.Request.Path == new PathString("/first"))
{
Assert.False(value.HasValue);
value = 1;
context.Session.SetInt32("Key", 1);
}
else if (context.Request.Path == new PathString("/second"))
{
Assert.False(value.HasValue);
value = 2;
}
return context.Response.WriteAsync(value.Value.ToString());
});
},
services =>
{
services.AddInstance(typeof(ILoggerFactory), loggerFactory);
services.AddCaching();
services.AddSession(o => o.IdleTimeout = TimeSpan.FromMilliseconds(30));
}))
{
var client = server.CreateClient();
var response = await client.GetAsync("first");
response.EnsureSuccessStatusCode();
client = server.CreateClient();
var cookie = SetCookieHeaderValue.ParseList(response.Headers.GetValues("Set-Cookie").ToList()).First();
client.DefaultRequestHeaders.Add("Cookie", new CookieHeaderValue(cookie.Name, cookie.Value).ToString());
Thread.Sleep(50);
Assert.Equal("2", await client.GetStringAsync("/second"));
var sessionLogMessages = sink.Writes.OnlyMessagesFromSource<DistributedSession>().ToArray();
Assert.Equal(2, sessionLogMessages.Length);
Assert.Contains("started", sessionLogMessages[0].State.ToString());
Assert.Contains("expired", sessionLogMessages[1].State.ToString());
Assert.Equal(LogLevel.Information, sessionLogMessages[0].LogLevel);
Assert.Equal(LogLevel.Warning, sessionLogMessages[1].LogLevel);
}
}
public async Task SessionStart_LogsInformation()
{
var sink = new TestSink();
var loggerFactory = new TestLoggerFactory(sink, enabled: true);
using (var server = TestServer.Create(app =>
{
app.UseSession();
app.Run(context =>
{
context.Session.SetString("Key", "Value");
return Task.FromResult(0);
});
},
services =>
{
services.AddInstance(typeof(ILoggerFactory), loggerFactory);
services.AddCaching();
services.AddSession();
}))
{
var client = server.CreateClient();
var response = await client.GetAsync(string.Empty);
response.EnsureSuccessStatusCode();
var sessionLogMessages = sink.Writes.OnlyMessagesFromSource<DistributedSession>().ToArray();
Assert.Single(sessionLogMessages);
Assert.Contains("started", sessionLogMessages[0].State.ToString());
Assert.Equal(LogLevel.Information, sessionLogMessages[0].LogLevel);
}
}
