Skip to content

Commit

Permalink
logging: Explode LoggingHandler into LoggingRequestHandler, LoggingRe…
Browse files Browse the repository at this point in the history 
…questResponseHandler
  • Loading branch information
@rmandvikar
rmandvikar committed Nov 5, 2023
1 parent 7c8c1bc commit 0aefb7e
Show file tree
Hide file tree
Showing 5 changed files with 145 additions and 84 deletions.
41 changes: 41 additions & 0 deletions src/rm.DelegatingHandlers/LoggingRequestHandler.cs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,41 @@
using System;
using System.Net.Http;
using System.Threading;
using System.Threading.Tasks;
using rm.DelegatingHandlers.Formatting;
using Serilog;

namespace rm.DelegatingHandlers;

/// <summary>
/// Logs <see cref="HttpRequestMessage"/>.
/// </summary>
public class LoggingRequestHandler : DelegatingHandler
{
private readonly ILogger logger;
private readonly ILoggingFormatter loggingFormatter;

/// <inheritdoc cref="LoggingRequestHandler" />
public LoggingRequestHandler(
ILogger logger,
ILoggingFormatter loggingFormatter)
{
this.logger = logger?.ForContext(GetType())
?? throw new ArgumentNullException(nameof(logger));
this.loggingFormatter = loggingFormatter
?? throw new ArgumentNullException(nameof(loggingFormatter));
}

protected override async Task<HttpResponseMessage> SendAsync(
HttpRequestMessage request,
CancellationToken cancellationToken)
{
ILogger lRequest = logger;
lRequest = await lRequest.ForContextAsync(request, loggingFormatter)
.ConfigureAwait(false);
lRequest.Information("request/");

return await base.SendAsync(request, cancellationToken)
.ConfigureAwait(false);
}
}
11 changes: 3 additions & 8 deletions src/rm.DelegatingHandlers/LoggingHandler.cs → ...Handlers/LoggingRequestResponseHandler.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,13 +12,13 @@ namespace rm.DelegatingHandlers;
/// Logs <see cref="HttpRequestMessage"/>, and <see cref="HttpResponseMessage"/> with
/// exception, if any, along with its elapsed time.
/// </summary>
public class LoggingHandler : DelegatingHandler
public class LoggingRequestResponseHandler : DelegatingHandler
{
private readonly ILogger logger;
private readonly ILoggingFormatter loggingFormatter;

/// <inheritdoc cref="LoggingHandler" />
public LoggingHandler(
/// <inheritdoc cref="LoggingRequestResponseHandler" />
public LoggingRequestResponseHandler(
ILogger logger,
ILoggingFormatter loggingFormatter)
{
Expand All @@ -32,11 +32,6 @@ protected override async Task<HttpResponseMessage> SendAsync(
HttpRequestMessage request,
CancellationToken cancellationToken)
{
ILogger lRequest = logger;
lRequest = await lRequest.ForContextAsync(request, loggingFormatter)
.ConfigureAwait(false);
lRequest.Information("request/");

var stopwatch = Stopwatch.StartNew();
try
{
Expand Down
10 changes: 8 additions & 2 deletions tests/rm.DelegatingHandlersTest/Http2HandlerTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,20 +26,26 @@ public async Task Sends_Http2()
new HttpRequestMessage(method, uri);

var http2Handler = new Http2Handler();
var loggingHandler = new LoggingHandler(logger, new LoggingFormatter());
var loggingRequestResponseHandler = new LoggingRequestResponseHandler(logger, new LoggingFormatter());
var loggingRequestHandler = new LoggingRequestHandler(logger, new LoggingFormatter());

using var httpclient = HttpClientFactory.Create(
#if NETFRAMEWORK
new WinHttpHandler(),
#endif
http2Handler, loggingHandler);
loggingRequestResponseHandler, http2Handler, loggingRequestHandler);

using var _ = await httpclient.SendAsync(request, CancellationToken.None);

InMemorySink.Instance.Should()
.HaveMessage("request/").Appearing().Once()
.WithProperty($"request.Version").WithValue(version)
;

InMemorySink.Instance.Should()
.HaveMessage("request/response").Appearing().Once()
.WithProperty($"request.Version").WithValue(version)
;
InMemorySink.Instance.Should()
.HaveMessage("request/response").Appearing().Once()
.WithProperty($"response.Version").WithValue(version)
Expand Down
80 changes: 80 additions & 0 deletions tests/rm.DelegatingHandlersTest/LoggingRequestHandlerTests.cs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,80 @@
using System.Text;
using FluentAssertions;
using NUnit.Framework;
using rm.DelegatingHandlers;
using rm.DelegatingHandlers.Formatting;
using Serilog;
using Serilog.Events;
using Serilog.Formatting.Json;
using Serilog.Sinks.InMemory;
using Serilog.Sinks.InMemory.Assertions;

namespace rm.DelegatingHandlersTest;

[TestFixture]
public class LoggingRequestHandlerTests
{
public class Formatter
{
[Test]
public async Task Logs_Request()
{
var logger = new LoggerConfiguration()
.MinimumLevel.Verbose()
.WriteTo.InMemory()
.WriteTo.Console(new JsonFormatter())
.CreateLogger();
var version = "2.0";
var method = HttpMethod.Post;
var uri = "/health";
var requestContent = "woot?!";
var encoding = Encoding.UTF8;
var mimeType = MediaTypeNames.Application.Json;
var header1 = "header1";
var headerValue1 = "headerValue1";
var header2 = "header02";
var headerValue2 = "headerValue02";
var property1 = "property1";
var propertyValue1 = "propertyValue1";
var property2 = "property02";
var propertyValue2 = "propertyValue02";
using var request =
new HttpRequestMessage(method, uri)
{
Version = new Version(version),
Content = new StringContent(requestContent, encoding, mimeType),
};
request.Headers.Add(header1, headerValue1);
request.Headers.Add(header2, headerValue2);
#pragma warning disable CS0618 // Type or member is obsolete
request.Properties.Add(property1, propertyValue1);
request.Properties.Add(property2, propertyValue2);
#pragma warning restore CS0618 // Type or member is obsolete

var shortCircuitingCannedResponseHandler = new ShortCircuitingCannedResponseHandler(new HttpResponseMessage());
var loggingRequestHandler = new LoggingRequestHandler(logger, new LoggingFormatter());

using var invoker = HttpMessageInvokerFactory.Create(
loggingRequestHandler, shortCircuitingCannedResponseHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

InMemorySink.Instance.Should()
.HaveMessage("request/").Appearing().Once()
.WithLevel(LogEventLevel.Information)
.WithProperty($"request.Version").WithValue(version)
.And.WithProperty($"request.HttpMethod").WithValue(method.ToString())
.And.WithProperty($"request.Uri").WithValue(uri)
.And.WithProperty($"request.Header.{header1}").WithValue(headerValue1)
.And.WithProperty($"request.Header.{header2}").WithValue(headerValue2)
.And.WithProperty($"request.Content.Header.Content-Type").WithValue($"{mimeType}; charset={encoding.BodyName}")
#if NET6_0_OR_GREATER
.And.WithProperty($"request.Content.Header.Content-Length").WithValue(requestContent.Length.ToString())
#endif
.And.WithProperty($"request.Content").WithValue(requestContent)
.And.WithProperty($"request.Property.{property1}").WithValue(propertyValue1)
.And.WithProperty($"request.Property.{property2}").WithValue(propertyValue2)
;
}
}
}
87 changes: 13 additions & 74 deletions ...gatingHandlersTest/LoggingHandlerTests.cs → ...est/LoggingRequestResponseHandlerTests.cs
View file
Original file line number Diff line number Diff line change
@@ -1,8 +1,9 @@
using System.Net;
using System.Text;
using AutoFixture.AutoMoq;
using AutoFixture;
using AutoFixture.AutoMoq;
using FluentAssertions;
using Moq;
using NUnit.Framework;
using rm.DelegatingHandlers;
using rm.DelegatingHandlers.Formatting;
Expand All @@ -14,78 +15,16 @@
using Serilog.Formatting.Json;
using Serilog.Sinks.InMemory;
using Serilog.Sinks.InMemory.Assertions;
using Moq;

namespace rm.DelegatingHandlersTest;

[TestFixture]
public class LoggingHandlerTests
public class LoggingRequestResponseHandlerTests
{
private static readonly Random rng = RandomFactory.GetThreadStaticRandom();

public class Formatter
{
[Test]
public async Task Logs_Request()
{
var logger = new LoggerConfiguration()
.MinimumLevel.Verbose()
.WriteTo.InMemory()
.WriteTo.Console(new JsonFormatter())
.CreateLogger();
var version = "2.0";
var method = HttpMethod.Post;
var uri = "/health";
var requestContent = "woot?!";
var encoding = Encoding.UTF8;
var mimeType = MediaTypeNames.Application.Json;
var header1 = "header1";
var headerValue1 = "headerValue1";
var header2 = "header02";
var headerValue2 = "headerValue02";
var property1 = "property1";
var propertyValue1 = "propertyValue1";
var property2 = "property02";
var propertyValue2 = "propertyValue02";
using var request =
new HttpRequestMessage(method, uri)
{
Version = new Version(version),
Content = new StringContent(requestContent, encoding, mimeType),
};
request.Headers.Add(header1, headerValue1);
request.Headers.Add(header2, headerValue2);
#pragma warning disable CS0618 // Type or member is obsolete
request.Properties.Add(property1, propertyValue1);
request.Properties.Add(property2, propertyValue2);
#pragma warning restore CS0618 // Type or member is obsolete

var shortCircuitingCannedResponseHandler = new ShortCircuitingCannedResponseHandler(new HttpResponseMessage());
var loggingHandler = new LoggingHandler(logger, new LoggingFormatter());

using var invoker = HttpMessageInvokerFactory.Create(
loggingHandler, shortCircuitingCannedResponseHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

InMemorySink.Instance.Should()
.HaveMessage("request/").Appearing().Once()
.WithLevel(LogEventLevel.Information)
.WithProperty($"request.Version").WithValue(version)
.And.WithProperty($"request.HttpMethod").WithValue(method.ToString())
.And.WithProperty($"request.Uri").WithValue(uri)
.And.WithProperty($"request.Header.{header1}").WithValue(headerValue1)
.And.WithProperty($"request.Header.{header2}").WithValue(headerValue2)
.And.WithProperty($"request.Content.Header.Content-Type").WithValue($"{mimeType}; charset={encoding.BodyName}")
#if NET6_0_OR_GREATER
.And.WithProperty($"request.Content.Header.Content-Length").WithValue(requestContent.Length.ToString())
#endif
.And.WithProperty($"request.Content").WithValue(requestContent)
.And.WithProperty($"request.Property.{property1}").WithValue(propertyValue1)
.And.WithProperty($"request.Property.{property2}").WithValue(propertyValue2)
;
}

[Test]
public async Task Logs_Request_Response()
{
Expand Down Expand Up @@ -147,10 +86,10 @@ public async Task Logs_Request_Response()
#pragma warning restore CS0618 // Type or member is obsolete
return Task.FromResult(response);
});
var loggingHandler = new LoggingHandler(logger, new LoggingFormatter());
var loggingRequestResponseHandler = new LoggingRequestResponseHandler(logger, new LoggingFormatter());

using var invoker = HttpMessageInvokerFactory.Create(
loggingHandler, delegateHandler, shortCircuitingCannedResponseHandler);
loggingRequestResponseHandler, delegateHandler, shortCircuitingCannedResponseHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

Expand Down Expand Up @@ -235,11 +174,11 @@ public async Task Logs_Request_Exception()
response.Headers.Add(header2, headerValue2);

var swallowingHandler = new SwallowingHandler(ex => ex is TurnDownForWhatException);
var loggingHandler = new LoggingHandler(logger, new LoggingFormatter());
var loggingRequestResponseHandler = new LoggingRequestResponseHandler(logger, new LoggingFormatter());
var throwingHandler = new ThrowingHandler(new TurnDownForWhatException());

using var invoker = HttpMessageInvokerFactory.Create(
swallowingHandler, loggingHandler, throwingHandler);
swallowingHandler, loggingRequestResponseHandler, throwingHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

Expand Down Expand Up @@ -316,10 +255,10 @@ public async Task Logs_Request_Response_Compact()
#endif

var shortCircuitingCannedResponseHandler = new ShortCircuitingCannedResponseHandler(response);
var loggingHandler = new LoggingHandler(logger, new CompactLoggingFormatter());
var loggingRequestResponseHandler = new LoggingRequestResponseHandler(logger, new CompactLoggingFormatter());

using var invoker = HttpMessageInvokerFactory.Create(
loggingHandler, shortCircuitingCannedResponseHandler);
loggingRequestResponseHandler, shortCircuitingCannedResponseHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

Expand Down Expand Up @@ -404,10 +343,10 @@ public async Task Logs_Request_Exception_Compact()

var swallowingHandler = new SwallowingHandler(ex => ex is TurnDownForWhatException);
var throwingHandler = new ThrowingHandler(new TurnDownForWhatException());
var loggingHandler = new LoggingHandler(logger, new CompactLoggingFormatter());
var loggingRequestResponseHandler = new LoggingRequestResponseHandler(logger, new CompactLoggingFormatter());

using var invoker = HttpMessageInvokerFactory.Create(
swallowingHandler, loggingHandler, throwingHandler);
swallowingHandler, loggingRequestResponseHandler, throwingHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

Expand Down Expand Up @@ -489,10 +428,10 @@ public async Task Logs_Request_Response_Sampling()
using var request = new HttpRequestMessage(HttpMethod.Get, $"/{id}");

var shortCircuitingCannedResponseHandler = new ShortCircuitingCannedResponseHandler(new HttpResponseMessage());
var loggingHandler = new LoggingHandler(logger, new CompactLoggingFormatter());
var loggingRequestResponseHandler = new LoggingRequestResponseHandler(logger, new CompactLoggingFormatter());

using var invoker = HttpMessageInvokerFactory.Create(
loggingHandler, shortCircuitingCannedResponseHandler);
loggingRequestResponseHandler, shortCircuitingCannedResponseHandler);

using var _ = await invoker.SendAsync(request, CancellationToken.None);

Expand Down

0 comments on commit 0aefb7e

Please sign in to comment.