public async Task When_InvokingMiddlewareWithPathAndIgnorePattern_Expect_Logged(string path, string ignorePattern, bool logged)
{
// Arrange
Mock <ILogger <RequestLoggingMiddleware> > mock = new Mock <ILogger <RequestLoggingMiddleware> >();
mock.Setup(m => m.IsEnabled(It.IsAny <LogLevel>())).Returns(true);
RequestLoggingMiddleware.Options options = new RequestLoggingMiddleware.Options
{
IgnorePatterns = new string[] { ignorePattern },
};
RequestLoggingMiddleware middleware = new RequestLoggingMiddleware(
(httpContext) => Task.CompletedTask,
mock.Object,
Options.Create(options));
HttpContext context = new DefaultHttpContext();
context.Request.Path = path;
// Act
await middleware.Invoke(context);
// Assert
mock.Verify(
m => m.Log(
It.IsAny <LogLevel>(),
It.IsAny <EventId>(),
It.IsAny <It.IsAnyType>(),
null,
(Func <It.IsAnyType, Exception, string>)It.IsAny <object>()),
Times.Exactly(logged ? 2 : 0));
}
public void Configure(IApplicationBuilder app)
{
var appConfig = new AppConfiguration();
_config.Bind(appConfig);
Console.WriteLine("Configuring with EnableAuthorization=" + appConfig.EnableAuthorization);
var levelSwitch = new LoggingLevelSwitch();
var log = ConfigureLogger(levelSwitch, appConfig);
app.UseCors("default");
app.UseIdentityServerAuthentication(new IdentityServerAuthenticationOptions
{
Authority = appConfig.Authority,
RequireHttpsMetadata = false,
ApiName = appConfig.ClientId,
});
app.UseOwin(buildFunc =>
{
buildFunc(next => GlobalErrorLoggingMiddleware.Inject(next, log));
buildFunc(CorrelationTokenMiddleware.Inject);
buildFunc(next => RequestLoggingMiddleware.Inject(next, log));
buildFunc(next => PerformanceLoggingMiddleware.Inject(next, log));
buildFunc(next => new DiagnosticsMiddleware(next, levelSwitch).Inject);
buildFunc(next => new MonitoringMiddleware(next, HealthCheck).Inject);
if (appConfig.EnableAuthorization)
{
buildFunc.UseAuthPlatform(appConfig.Scopes.Split(','));
}
buildFunc.UseNancy(opt => opt.Bootstrapper = new Bootstrapper(log, appConfig));
});
}
public async Task Connection_Information_Should_Be_Logged()
{
var logger = A.Fake <IEventLogger <RequestLoggingMiddleware> >();
RequestLoggingMiddleware middleware = new RequestLoggingMiddleware(logger);
var context = A.Fake <HttpContext>();
var connectionInfo = A.Fake <ConnectionInfo>();
A.CallTo(() => context.Connection).Returns(connectionInfo);
A.CallTo(() => connectionInfo.Id).Returns("dummy");
A.CallTo(() => connectionInfo.LocalIpAddress).Returns(IPAddress.Parse("1.1.1.1"));
A.CallTo(() => connectionInfo.LocalPort).Returns(1234);
A.CallTo(() => connectionInfo.RemoteIpAddress).Returns(IPAddress.Parse("2.2.2.2"));
A.CallTo(() => connectionInfo.RemotePort).Returns(4321);
await middleware.Invoke(context, () => Task.CompletedTask);
A.CallTo(logger)
.Where(call => call.Method.Name == "BeginScope")
.WhenArgumentsMatch(args =>
{
dynamic data = args[0];
var connection = data.Connection;
return(connection.Id == "dummy" &&
connection.LocalIpAddress.ToString() == "1.1.1.1" &&
connection.LocalPort == 1234 &&
connection.RemoteIpAddress.ToString() == "2.2.2.2" &&
connection.RemotePort == 4321);
}).MustHaveHappened();
}
public async void PostrequestLogFormattedCorrectlyTest()
{
RequestDelegate requestDelegate = (innerHttpContext) => Task.CompletedTask;
var middleware = new RequestLoggingMiddleware(requestDelegate, _loggerMock.Object);
var context = new DefaultHttpContext();
var path = "/test";
var size = 50;
context.Request.Path = new PathString(path);
context.Request.ContentLength = size;
await middleware.Invoke(context);
// TODO: find way to test timer
var expectedStart = $"{{\"id\": \"{context.TraceIdentifier}\", " +
$"\"request\": \"{path}\", \"time\": ";
_loggerMock.Verify(
x => x.Log <object>(
LogLevel.Information,
It.IsAny <EventId>(),
It.Is <object>(y => y.ToString().StartsWith(expectedStart)),
It.IsAny <Exception>(),
It.IsAny <Func <object, Exception, string> >()),
Times.Once());
}
public void RequestLoggingMiddleware_Inject_CallsLogger()
{
//Arrange
var ctx = new OwinContext
{
Request =
{
Scheme = LibOwin.Infrastructure.Constants.Https,
Path = new PathString("/logtest"),
Method = "GET"
}
};
//ctx.Request.Headers.Add("TestHeader", new[] {"TestHeaderValue"});
var loggerMock = new Mock <ILogger>();
loggerMock.Setup(logger => logger.ForContext <RequestLoggingMiddleware>()).Returns(() => loggerMock.Object);
loggerMock.Setup(logger => logger.Information(It.IsAny <string>(), It.IsAny <string>(), It.IsAny <object>(), It.IsAny <object>())).Verifiable();
loggerMock.Setup(logger => logger.Information(It.IsAny <string>(), It.IsAny <int>(), It.IsAny <object>())).Verifiable();
//Act
var pipeline = RequestLoggingMiddleware.Inject(_noOp, loggerMock.Object);
pipeline(ctx.Environment);
//Assert
loggerMock.Verify();
}
public async Task When_InvokingMiddlewareWithStatusCode_Expect_LogLevel(int statusCode, LogLevel expectedLogLevel)
{
// Arrange
Mock <ILogger <RequestLoggingMiddleware> > mock = new Mock <ILogger <RequestLoggingMiddleware> >();
mock.Setup(m => m.IsEnabled(It.IsAny <LogLevel>())).Returns(true);
RequestLoggingMiddleware middleware = new RequestLoggingMiddleware(
(httpContext) => Task.CompletedTask,
mock.Object,
Options.Create(new RequestLoggingMiddleware.Options()));
HttpContext context = new DefaultHttpContext();
context.Response.StatusCode = statusCode;
// Act
await middleware.Invoke(context);
// Assert
mock.Verify(
m => m.Log(
LogLevel.Information,
It.IsAny <EventId>(),
It.Is <It.IsAnyType>((@object, type) => @object.ToString()
!.Equals("Inbound HTTP started")),
null,
(Func <It.IsAnyType, Exception, string>)It.IsAny <object>()),
Times.Once);
mock.Verify(
m => m.Log(
expectedLogLevel,
It.IsAny <EventId>(),
It.Is <It.IsAnyType>((@object, type) => @object.ToString()
!.Equals($"Inbound HTTP finished - {statusCode}")),
null,
(Func <It.IsAnyType, Exception, string>)It.IsAny <object>()),
Times.Once());
}
public async Task Invoke_logs_as_expected()
{
var logger = new LoggerConfiguration()
.WriteTo.TestCorrelator()
.CreateLogger();
var mw = new RequestLoggingMiddleware((innerHttpContext) => Task.FromResult(0), Helpers.MockIAppSettings(), logger);
var context = TestContext();
using (TestCorrelator.CreateContext())
{
await mw.InvokeAsync(context);
var logEvent = TestCorrelator.GetLogEventsFromCurrentContext().FirstOrDefault();
using var scope = new AssertionScope();
logEvent.Should().NotBeNull();
Assert.AreEqual(RequestLoggingMiddleware.DBG_LOG_TEMPLATE, logEvent.MessageTemplate.Text);
logEvent.Level.Should().Be(LogEventLevel.Information);
}
}
