feat(middleware): logging detailed + per request config (#11)

* feat(middleware): logging detailed + per request config

* update comment

* add more tests for merged logging options + minor refactoring when getting options

* update changelogs

Author: stephenlautier

CHANGELOG.md

@@ -1,6 +1,14 @@
 # Fluently Http Changelog
 
-[*vNext*](https://github.com/sketch7/FluentlyHttpClient/compare/1.3.0...1.3.1) (201X-X-X)
+[*vNext*](https://github.com/sketch7/FluentlyHttpClient/compare/1.4.0...1.4.1) (201X-X-X)
+
+## [1.4.0](https://github.com/sketch7/FluentlyHttpClient/compare/1.3.0...1.4.0) (2018-03-03)
+
+### Features
+ - **logger middleware:** add `LoggerHttpMiddlewareOptions` to configure `ShouldLogDetailedRequest` and `ShouldLogDetailedResponse`.
+ - **logger middleware:** add `WithLoggingOptions` on request builder, to specify options per request.
+ - **timer middleware:** add `WithTimerWarnThreshold` on request builder, to specify options per request.
+
 
 ## [1.3.0](https://github.com/sketch7/FluentlyHttpClient/compare/1.2.1...1.3.0) (2018-02-24)
 

README.md

@@ -294,7 +294,7 @@ namespace FluentlyHttpClient
     // Response extension methods - useful to extend FluentHttpResponse
     public static class TimerFluentResponseExtensions
     {
-        private const string TimeTakenKey = "TIME_TAKEN";
+        private const string TimeTakenKey = "TIMER_TIME_TAKEN";
 
         public static void SetTimeTaken(this FluentHttpResponse response, TimeSpan value)
           => response.Items.Add(TimeTakenKey, value);

package.json

@@ -1,6 +1,6 @@
 {
   "name": "@sketch7/fluently-http-client",
-  "version": "1.3.0",
+  "version": "1.4.0",
   "scripts": {
     "pack": "bash ./tools/pack.sh",
     "prepublish:dev": "npm run pack",

src/FluentlyHttpClient/Middleware/LoggerHttpMiddleware.cs

@@ -4,35 +4,68 @@
 
 namespace FluentlyHttpClient.Middleware
 {
+	/// <summary>
+	/// Logger HTTP middleware options.
+	/// </summary>
+	public class LoggerHttpMiddlewareOptions
+	{
+		/// <summary>
+		/// Gets or sets whether the request log should be detailed e.g. include body. Note: This should only be enabled for development or as needed,
+		/// as it will reduce performance.
+		/// </summary>
+		public bool? ShouldLogDetailedRequest { get; set; }
+
+		/// <summary>
+		/// Gets or sets whether the response log should be detailed e.g. include body. Note: This should only be enabled for development or as needed,
+		/// as it will reduce performance.
+		/// </summary>
+		public bool? ShouldLogDetailedResponse { get; set; }
+	}
+
 	/// <summary>
 	/// Logging middleware for HTTP client.
 	/// </summary>
 	public class LoggerHttpMiddleware : IFluentHttpMiddleware
 	{
 		private readonly FluentHttpRequestDelegate _next;
+		private readonly LoggerHttpMiddlewareOptions _options;
 		private readonly ILogger _logger;
 
 		/// <summary>
 		/// Initializes a new instance.
 		/// </summary>
-		public LoggerHttpMiddleware(FluentHttpRequestDelegate next, ILogger<LoggerHttpMiddleware> logger)
+		public LoggerHttpMiddleware(FluentHttpRequestDelegate next, LoggerHttpMiddlewareOptions options, ILogger<LoggerHttpMiddleware> logger)
 		{
 			_next = next;
+			_options = options;
 			_logger = logger;
 		}
 
-		/// <summary>
-		/// Function to invoke.
-		/// </summary>
+		/// <inheritdoc />
 		public async Task<FluentHttpResponse> Invoke(FluentHttpRequest request)
 		{
-			if (_logger.IsEnabled(LogLevel.Information))
+			if (!_logger.IsEnabled(LogLevel.Information))
+				return await _next(request);
+
+			var options = request.GetLoggingOptions(_options);
+			if (request.Message.Content == null || !options.ShouldLogDetailedRequest.GetValueOrDefault(false))
 				_logger.LogInformation("Pre-request... {request}", request);
+			else
+			{
+				var requestContent = await request.Message.Content.ReadAsStringAsync();
+				_logger.LogInformation("Pre-request... {request}\nContent: {requestContent}", request, requestContent);
+			}
 
 			var response = await _next(request);
 
-			if (_logger.IsEnabled(LogLevel.Information))
+			if (response.Content == null || !options.ShouldLogDetailedResponse.GetValueOrDefault(false))
+			{
 				_logger.LogInformation("Post-request... {response}", response);
+				return response;
+			}
+
+			var responseContent = await response.Content.ReadAsStringAsync();
+			_logger.LogInformation("Post-request... {response}\nContent: {responseContent}", response, responseContent);
 			return response;
 		}
 	}
@@ -45,11 +78,44 @@ namespace FluentlyHttpClient
 	/// </summary>
 	public static class LoggerHttpMiddlwareExtensions
 	{
+		private const string LoggingOptionsKey = "LOGGING_OPTIONS";
+
+		#region Request Extensions
+		/// <summary>
+		/// Set logging options for the request.
+		/// </summary>
+		/// <param name="requestBuilder">Request builder instance.</param>
+		/// <param name="options">Logging options to set.</param>
+		public static FluentHttpRequestBuilder WithLoggingOptions(this FluentHttpRequestBuilder requestBuilder, LoggerHttpMiddlewareOptions options)
+		{
+			requestBuilder.Items[LoggingOptionsKey] = options;
+			return requestBuilder;
+		}
+
+		/// <summary>
+		/// Get logging option for the request.
+		/// </summary>
+		/// <param name="request">Request to get options from.</param>
+		/// <param name="defaultOptions"></param>
+		/// <returns>Returns merged logging options.</returns>
+		public static LoggerHttpMiddlewareOptions GetLoggingOptions(this FluentHttpRequest request, LoggerHttpMiddlewareOptions defaultOptions = null)
+		{
+			if (!request.Items.TryGetValue(LoggingOptionsKey, out var result)) return defaultOptions;
+			var options = (LoggerHttpMiddlewareOptions)result;
+			if (defaultOptions == null)
+				return options;
+			options.ShouldLogDetailedRequest = options.ShouldLogDetailedRequest ?? defaultOptions.ShouldLogDetailedRequest;
+			options.ShouldLogDetailedResponse = options.ShouldLogDetailedResponse ?? defaultOptions.ShouldLogDetailedResponse;
+			return options;
+		}
+		#endregion
+
 		/// <summary>
 		/// Use logger middleware which logs out going requests and incoming responses.
 		/// </summary>
 		/// <param name="builder">Builder instance</param>
-		public static FluentHttpClientBuilder UseLogging(this FluentHttpClientBuilder builder)
-			=> builder.UseMiddleware<LoggerHttpMiddleware>();
+		/// <param name="options"></param>
+		public static FluentHttpClientBuilder UseLogging(this FluentHttpClientBuilder builder, LoggerHttpMiddlewareOptions options = null)
+			=> builder.UseMiddleware<LoggerHttpMiddleware>(options ?? new LoggerHttpMiddlewareOptions());
 	}
 }

src/FluentlyHttpClient/Middleware/TimerHttpMiddleware.cs

@@ -22,6 +22,7 @@ public class TimerHttpMiddlewareOptions
 	/// </summary>
 	public class TimerHttpMiddleware : IFluentHttpMiddleware
 	{
+		private const string TimeTakenMessage = "Executed request {request} in {timeTakenMillis}ms";
 		private readonly FluentHttpRequestDelegate _next;
 		private readonly TimerHttpMiddlewareOptions _options;
 		private readonly ILogger _logger;
@@ -35,23 +36,23 @@ public TimerHttpMiddleware(FluentHttpRequestDelegate next, TimerHttpMiddlewareOp
 			_options = options;
 			_logger = logger;
 
-			if(_options.WarnThreshold <= TimeSpan.Zero)
+			if (_options.WarnThreshold <= TimeSpan.Zero)
 				throw new ArgumentException($"{nameof(_options.WarnThreshold)} must be greater than Zero.");
 		}
 
-		/// <summary>
-		/// Function to invoke.
-		/// </summary>
+		/// <inheritdoc />
 		public async Task<FluentHttpResponse> Invoke(FluentHttpRequest request)
 		{
 			var watch = Stopwatch.StartNew();
 			var response = await _next(request);
 			var elapsed = watch.Elapsed;
-			
-			if (_logger.IsEnabled(LogLevel.Warning) && elapsed > _options.WarnThreshold)
-				_logger.LogWarning("Executed request {request} in {timeTakenMillis}ms", request, elapsed.TotalMilliseconds);
+			var threshold = request.GetTimerWarnThreshold()
+				.GetValueOrDefault(_options.WarnThreshold);
+
+			if (_logger.IsEnabled(LogLevel.Warning) && elapsed > threshold)
+				_logger.LogWarning(TimeTakenMessage, request, elapsed.TotalMilliseconds);
 			else if (_logger.IsEnabled(LogLevel.Information))
-				_logger.LogInformation("Executed request {request} in {timeTakenMillis}ms", request, elapsed.TotalMilliseconds);
+				_logger.LogInformation(TimeTakenMessage, request, elapsed.TotalMilliseconds);
 
 			response.SetTimeTaken(elapsed);
 			return response;
@@ -66,8 +67,35 @@ namespace FluentlyHttpClient
 	/// </summary>
 	public static class TimerHttpMiddlwareExtensions
 	{
-		private const string TimeTakenKey = "TIME_TAKEN";
+		private const string TimeTakenKey = "TIMER_TIME_TAKEN";
+		private const string WarnThresholdOptionKey = "TIMER_OPTION_WARN_THRESHOLD";
+
+		#region Request Extensions
+		/// <summary>
+		/// Set timer warn threshold for request.
+		/// </summary>
+		/// <param name="requestBuilder">Request builder instance.</param>
+		/// <param name="value">Timespan value.</param>
+		public static FluentHttpRequestBuilder WithTimerWarnThreshold(this FluentHttpRequestBuilder requestBuilder, TimeSpan value)
+		{
+			requestBuilder.Items[WarnThresholdOptionKey] = value;
+			return requestBuilder;
+		}
+
+		/// <summary>
+		/// Get timer warn threshold option for the request.
+		/// </summary>
+		/// <param name="request">Request to get time from.</param>
+		/// <returns>Returns timespan for the time taken.</returns>
+		public static TimeSpan? GetTimerWarnThreshold(this FluentHttpRequest request)
+		{
+			if (request.Items.TryGetValue(WarnThresholdOptionKey, out var result))
+				return (TimeSpan)result;
+			return null;
+		}
+		#endregion
 
+		#region Response Extensions
 		/// <summary>
 		/// Set time taken.
 		/// </summary>
@@ -83,6 +111,7 @@ public static void SetTimeTaken(this FluentHttpResponse response, TimeSpan value
 		/// <returns>Returns timespan for the time taken.</returns>
 		public static TimeSpan GetTimeTaken(this FluentHttpResponse response)
 			=> (TimeSpan)response.Items[TimeTakenKey];
+		#endregion
 
 		/// <summary>
 		/// Use timer middleware which measures how long the request takes.

test/FluentlyHttpClient.Test.csproj

@@ -10,6 +10,9 @@
     <PackageReference Include="Microsoft.Extensions.Logging" Version="2.0.0" />
     <PackageReference Include="Microsoft.NET.Test.Sdk" Version="15.5.0" />
     <PackageReference Include="RichardSzalay.MockHttp" Version="3.2.1" />
+    <PackageReference Include="Serilog.Extensions.Logging" Version="2.0.2" />
+    <PackageReference Include="Serilog.Sinks.Console" Version="3.1.1" />
+    <PackageReference Include="Serilog.Sinks.Debug" Version="1.0.0" />
     <PackageReference Include="xunit" Version="2.3.1" />
     <PackageReference Include="xunit.runner.visualstudio" Version="2.3.1" />
     <DotNetCliToolReference Include="dotnet-xunit" Version="2.3.1" />

test/Integration/SerilogIntegrationTest.cs

@@ -0,0 +1,64 @@
+using System;
+using System.Net.Http;
+using FluentlyHttpClient.Middleware;
+using Microsoft.Extensions.DependencyInjection;
+using RichardSzalay.MockHttp;
+using Serilog;
+using Xunit;
+
+namespace FluentlyHttpClient.Test.Integration
+{
+	public class SerilogIntegrationTest
+	{
+		private IServiceProvider BuildContainer()
+		{
+			Log.Logger = new LoggerConfiguration()
+				.WriteTo.Console()
+				.WriteTo.Debug()
+				.CreateLogger();
+			var container = new ServiceCollection()
+				.AddFluentlyHttpClient()
+				.AddLogging(x => x.AddSerilog());
+			return container.BuildServiceProvider();
+		}
+
+		[Fact]
+		public async void ShouldLogAll()
+		{
+			var mockHttp = new MockHttpMessageHandler();
+			mockHttp.When(HttpMethod.Post, "https://sketch7.com/api/heroes")
+				.Respond("application/json", "{ 'name': 'Azmodan', 'title': 'Lord of Sin' }");
+
+			var fluentHttpClientFactory = BuildContainer()
+				.GetRequiredService<IFluentHttpClientFactory>();
+
+			var clientBuilder = fluentHttpClientFactory.CreateBuilder("sketch7")
+				.WithBaseUrl("https://sketch7.com")
+				.UseLogging(new LoggerHttpMiddlewareOptions
+				{
+					ShouldLogDetailedResponse = false,
+					ShouldLogDetailedRequest = false
+				})
+				.WithMessageHandler(mockHttp);
+
+			var httpClient = fluentHttpClientFactory.Add(clientBuilder);
+			var hero = await httpClient.CreateRequest("/api/heroes")
+				.AsPost()
+				.WithBody(new Hero
+				{
+					Key = "valeera",
+					Name = "Valeera",
+					Title = "Shadow of the Ucrowned"
+				})
+				.WithLoggingOptions(new LoggerHttpMiddlewareOptions
+				{
+					ShouldLogDetailedRequest = false,
+					ShouldLogDetailedResponse = true
+				})
+				.Return<Hero>();
+
+			Assert.NotNull(hero);
+			Assert.Equal("Azmodan", hero.Name);
+		}
+	}
+}