public void BasicInfoLogger_LogBasicInfo_WritesErrorPostRequestDetails()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Trace);
Mock <IStopwatch> stopwatchMock = new();
stopwatchMock.SetupGet(stopwatch => stopwatch.Elapsed).Returns(TimeSpan.FromSeconds(3));
HttpContext context = new FakeHttpContextBuilder()
.SetMethod(HttpMethod.Post)
.SetScheme(HttpScheme.Http)
.SetHost(new("example.com"))
.SetPathBase("/primary")
.SetPath("/secondary")
.SetQuery(new() { { "cats", "1" } })
.SetStatus(HttpStatusCode.InternalServerError)
.Create();
var request = RequestDetails.From(context.Request);
var response = ResponseDetails.From(context.Response, stopwatchMock.Object);
BasicInfoLogger sut = new();
// Act
sut.LogBasicInfo(loggerMock.Object, request, response);
// Assert
loggerMock.VerifyLogging(
"POST http://example.com/primary/secondary?cats=1 at 00:00:03:000 with 500 InternalServerError",
LogLevel.Information);
}
public async Task RequestLogger_LogRequest_TraceWritesStatusAndHeadersAndBody()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Trace);
HttpContext context = new FakeHttpContextBuilder()
.SetResponseBody("conflict response content")
.SetResponseHeaders(new() { { "foo", new(new[] { "bar", "baz" }) } })
.SetStatus(HttpStatusCode.Conflict)
.Create();
Mock <IStopwatch> stopwatchMock = new();
var request = RequestDetails.From(context.Request);
var response = ResponseDetails.From(context.Response, stopwatchMock.Object);
ResponseLogger sut = new(new(null), new(null));
// Act
await sut.LogResponse(loggerMock.Object, request, response);
// Assert
loggerMock.VerifyLogging(
$"HTTP/1.1 409 Conflict{Environment.NewLine}" +
$"foo: bar,baz{Environment.NewLine}" +
$"{Environment.NewLine}" +
$"conflict response content{Environment.NewLine}",
LogLevel.Trace);
}
public void RequestDetails_From_CreatesFromHttpRequest()
{
// Arrange
HttpRequest request = new FakeHttpContextBuilder()
.SetMethod(HttpMethod.Put)
.SetScheme(HttpScheme.Http)
.SetPathBase("/api")
.SetPath("/v1")
.SetQuery(new() { { "cat", "1" } })
.SetHost(new("localhost"))
.Create()
.Request;
// Act
var result = RequestDetails.From(request);
// Assert
result.Should().NotBeNull()
.And.BeEquivalentTo(new RequestDetails
{
Method = "PUT",
Scheme = "http",
Host = "localhost",
Path = "/api/v1",
QueryString = "?cat=1",
Url = "http://localhost/api/v1?cat=1",
Protocol = "HTTP/1.1",
Headers = new Dictionary <string, StringValues> {
{ "Host", "localhost" }
}
}, options => options.Excluding(r => r.Content));
}
public void BasicInfoLogger_LogBasicInfo_WritesSuccessfulPostRequestDetails()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Trace);
Mock <IStopwatch> stopwatchMock = new();
stopwatchMock.SetupGet(stopwatch => stopwatch.Elapsed).Returns(TimeSpan.FromSeconds(2));
HttpContext context = new FakeHttpContextBuilder()
.SetRequest(
HttpMethod.Post,
HttpScheme.Https,
new() { { "cat", "221" } })
.Create();
var request = RequestDetails.From(context.Request);
var response = ResponseDetails.From(context.Response, stopwatchMock.Object);
BasicInfoLogger sut = new();
// Act
sut.LogBasicInfo(loggerMock.Object, request, response);
// Assert
loggerMock.VerifyLogging(
"POST https://localhost/master/slave?cat=221 at 00:00:02:000 with 200 OK",
LogLevel.Information);
}
public void RequestDetails_From_CreatesFromHttpRequestEmptyBasePath()
{
// Arrange
HttpRequest request = new FakeHttpContextBuilder()
.SetMethod(HttpMethod.Post)
.SetScheme(HttpScheme.Https)
.SetPath("/api/v2")
.SetHost(new("example.com"))
.Create()
.Request;
// Act
var result = RequestDetails.From(request);
// Assert
result.Should().NotBeNull()
.And.BeEquivalentTo(new RequestDetails
{
Method = "POST",
Scheme = "https",
Host = "example.com",
Path = "/api/v2",
QueryString = "",
Url = "https://example.com/api/v2",
Protocol = "HTTP/1.1",
Headers = new Dictionary <string, StringValues> {
{ "Host", "example.com" }
}
}, options => options.Excluding(r => r.Content));
}
public async Task HttpLogger_LogRequest_CallsLoggerWithRequestScope()
{
// Arrange
var(httpLogger, _, loggerMock, requestLoggerMock, _, _) = Mock();
HttpContext context = new FakeHttpContextBuilder()
.SetMethod(HttpMethod.Head)
.SetScheme(HttpScheme.Https)
.SetHost(new("example.com"))
.Create();
var request = RequestDetails.From(context.Request);
// Act
await httpLogger.LogRequest(request);
// Assert
requestLoggerMock.Verify(
requestLogger => requestLogger.LogRequest(loggerMock.Object, request),
Times.Once);
loggerMock.Verify(
MatchBeginScope(new()
{
{ "EventName", "HttpRequest" },
{ "Endpoint", "https://example.com" },
public async Task RequestLogger_LogRequest_TraceWritesUrlAndHeadersAndBody()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Trace);
HttpContext context = new FakeHttpContextBuilder()
.SetRequestBody("request content string")
.SetRequestHeaders(new() { { "foo", new(new[] { "bar", "baz" }) } })
.SetRequestContentType("text/plain")
.SetMethod(HttpMethod.Post)
.SetScheme(HttpScheme.Https)
.SetHost(new("example.org"))
.SetQuery(new() { { "foo", "bar" } })
.Create();
RequestLogger sut = new(new(null), new(null));
// Act
await sut.LogRequest(loggerMock.Object, RequestDetails.From(context.Request));
// Assert
loggerMock.VerifyLogging(
$"POST https://example.org?foo=bar HTTP/1.1{Environment.NewLine}" +
$"foo: bar,baz{Environment.NewLine}" +
$"Content-Type: text/plain{Environment.NewLine}" +
$"Host: example.org{Environment.NewLine}" +
$"{Environment.NewLine}" +
$"request content string{Environment.NewLine}",
LogLevel.Trace);
}
public void ContextLogger_Constructor_ProperlyCreatesMiddlewareLogger()
{
Mock <ILoggerFactory> loggerFactoryMock = new();
Mock <IHttpLoggerFactory> httpLoggerFactoryMock = new();
HttpContext context = new FakeHttpContextBuilder().Create();
ContextLogger <RequestLoggingMiddleware> sut = new(
loggerFactoryMock.Object,
httpLoggerFactoryMock.Object,
context);
loggerFactoryMock.Verify(
factory => factory.CreateLogger("Crip.AspNetCore.Logging.RequestLoggingMiddleware"),
Times.Once);
}
public async Task RequestLogger_LogRequest_WritesLogIfLevelIsSufficient(LogLevel level)
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(level);
HttpContext context = new FakeHttpContextBuilder().Create();
RequestLogger sut = new(new(null), new(null));
// Act
await sut.LogRequest(loggerMock.Object, RequestDetails.From(context.Request));
// Assert
loggerMock.Verify(
logger => logger.Log(
It.IsAny <LogLevel>(),
It.IsAny <EventId>(),
It.Is <It.IsAnyType>((v, t) => true),
It.IsAny <Exception>(),
It.Is <Func <It.IsAnyType, Exception, string> >((v, t) => true)),
Times.Once);
}
public async Task RequestLogger_LogRequest_DebugWritesOnlyStatusAndHeaders()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Debug);
HttpContext context = new FakeHttpContextBuilder()
.SetResponseHeaders(new() { { "foo", new(new[] { "bar", "baz" }) } })
.Create();
Mock <IStopwatch> stopwatchMock = new();
var request = RequestDetails.From(context.Request);
var response = ResponseDetails.From(context.Response, stopwatchMock.Object);
ResponseLogger sut = new(new(null), new(null));
// Act
await sut.LogResponse(loggerMock.Object, request, response);
// Assert
loggerMock.VerifyLogging(
$"HTTP/1.1 200 OK{Environment.NewLine}" +
$"foo: bar,baz{Environment.NewLine}",
LogLevel.Debug);
}
public async Task RequestLogger_LogRequest_AppliesContentMiddleware()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Trace);
Mock <IRequestContentLogMiddleware> contentMiddleware = new();
var contentMiddlewares = new List <IRequestContentLogMiddleware> {
contentMiddleware.Object
};
HttpContext context = new FakeHttpContextBuilder()
.SetResponseBody("response")
.SetResponseContentType("text/plain")
.Create();
Mock <IStopwatch> stopwatchMock = new();
var request = RequestDetails.From(context.Request);
var response = ResponseDetails.From(context.Response, stopwatchMock.Object);
LogContentFactory contentFactory = new(contentMiddlewares);
Stream modifiedContent = new MemoryStream(Encoding.UTF8.GetBytes("*modified*"));
ResponseLogger sut = new(contentFactory, new(null));
// Mock
contentMiddleware
.SetupGet(middleware => middleware.ContentType)
.Returns("text/plain");
contentMiddleware
.Setup(middleware => middleware.Modify(It.IsAny <Stream>(), It.IsAny <Stream>()))
.Callback <Stream, Stream>((input, output) => modifiedContent.CopyTo(output));
// Act
await sut.LogResponse(loggerMock.Object, request, response);
// Assert
loggerMock.VerifyLogging(
$"HTTP/1.1 200 OK{Environment.NewLine}" +
$"Content-Type: text/plain{Environment.NewLine}" +
$"{Environment.NewLine}" +
$"*modified*{Environment.NewLine}",
LogLevel.Trace);
}
public void BasicInfoLogger_LogBasicInfo_WritesLogIfLevelIsSufficient(LogLevel level)
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(level);
Mock <IStopwatch> stopwatchMock = new();
HttpContext context = new FakeHttpContextBuilder().Create();
var request = RequestDetails.From(context.Request);
var response = ResponseDetails.From(context.Response, stopwatchMock.Object);
BasicInfoLogger sut = new();
// Act
sut.LogBasicInfo(loggerMock.Object, request, response);
// Assert
loggerMock.Verify(
logger => logger.Log(
LogLevel.Information,
It.IsAny <EventId>(),
It.Is <It.IsAnyType>((v, t) => true),
It.IsAny <Exception>(),
It.Is <Func <It.IsAnyType, Exception, string> >((v, t) => true)),
Times.Once);
}
public async Task RequestLogger_LogRequest_DebugWritesOnlyUrlAndHeaders()
{
// Arrange
Mock <ILogger> loggerMock = CreateFor(LogLevel.Debug);
HttpContext context = new FakeHttpContextBuilder()
.SetRequest(
HttpMethod.Post,
HttpScheme.Https,
new() { { "foo", "bar" } },
new() { { "foo", new(new[] { "bar", "baz" }) } })
.Create();
RequestLogger sut = new(new(null), new(null));
// Act
await sut.LogRequest(loggerMock.Object, RequestDetails.From(context.Request));
// Assert
loggerMock.VerifyLogging(
$"POST https://localhost/master/slave?foo=bar HTTP/1.1{Environment.NewLine}" +
$"Host: localhost{Environment.NewLine}" +
$"foo: bar,baz{Environment.NewLine}",
LogLevel.Debug);
}
