Here is an example that uses middleware for logging each request response and other information.
Background
A middleware is a component class that is executed on every request in the ASP.NET application. There could be multiple middleware in the ASP.NET web application. It can be either framework provided or added via NuGet or your own custom middleware. This example uses middleware to log each request response and other information. Here, we will focus on how to generate and store logs using middleware.
Log Helpers
Log Model
This is the basic data structure of a log model, which contains information:
- Identifiers (project client, request, and other trace identifiers)
- Request data
- Response data
- Error information
public class RequestResponseLogModel
{
public string LogId { get; set; }
public string Node { get; set; }
public string ClientIp { get; set; }
public string TraceId { get; set; }
public DateTime? RequestDateTimeUtc { get; set; }
public DateTime? RequestDateTimeUtcActionLevel { get; set; }
public string RequestPath { get; set; }
public string RequestQuery { get; set; }
public List<KeyValuePair<string, string>> RequestQueries { get; set; }
public string RequestMethod { get; set; }
public string RequestScheme { get; set; }
public string RequestHost { get; set; }
public Dictionary<string, string> RequestHeaders { get; set; }
public string RequestBody { get; set; }
public string RequestContentType { get; set; }
public DateTime? ResponseDateTimeUtc { get; set; }
public DateTime? ResponseDateTimeUtcActionLevel { get; set; }
public string ResponseStatus { get; set; }
public Dictionary<string, string> ResponseHeaders { get; set; }
public string ResponseBody { get; set; }
public string ResponseContentType { get; set; }
public bool? IsExceptionActionLevel { get; set; }
public string ExceptionMessage { get; set; }
public string ExceptionStackTrace { get; set; }
public RequestResponseLogModel()
{
LogId = Guid.NewGuid().ToString();
}
}
Log Creator
The log creator will create/hold the log data model. Across the application, this will be used to assign necessary data to the log model. It is important to inject his creator class as scoped in the application. This means for every web request, a new instance of the class will be created. That way, it will be dedicated to a single request.
public interface IRequestResponseLogModelCreator
{
RequestResponseLogModel LogModel { get; }
string LogString();
}
public interface IRequestResponseLogger
{
void Log(IRequestResponseLogModelCreator logCreator);
}
public class RequestResponseLogModelCreator : IRequestResponseLogModelCreator
{
public RequestResponseLogModel LogModel { get; private set; }
public RequestResponseLogModelCreator()
{
LogModel = new RequestResponseLogModel();
}
public string LogString()
{
var jsonString = JsonConvert.SerializeObject(LogModel);
return jsonString;
}
}
Logger
This logger class is responsible to serialize the log model and store logs. A singleton object would be just fine for this purpose.
public interface IRequestResponseLogger
{
void Log(IRequestResponseLogModelCreator logCreator);
}
public class RequestResponseLogger : IRequestResponseLogger
{
private readonly ILogger<RequestResponseLogger> _logger;
public RequestResponseLogger(ILogger<RequestResponseLogger> logger)
{
_logger = logger;
}
public void Log(IRequestResponseLogModelCreator logCreator)
{
_logger.LogCritical(logCreator.LogString());
}
}
Log Option
This is a controlling mechanism. Middleware will create/log request/response data if IsEnabled
is true
.
public class RequestResponseLoggerOption
{
public bool IsEnabled { get; set; }
public string Name { get; set; }
public string DateTimeFormat { get; set; }
}
The option model will get serialized from app configuration or appsettings.json.
{
"RequestResponseLogger": {
"IsEnabled": true,
"Name": "Cpm.Web.Api",
"DateTimeFormat": "yyyy-MM-dd HH:mm:ss"
}
Middleware
Here, in InvokeAsync()
method, we are assigning values to the log model from HttpRequest
and HttpResponse
.
using Microsoft.AspNetCore.Diagnostics;
using Microsoft.AspNetCore.Http;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using Newtonsoft.Json;
using System;
using System.IO;
using System.Linq;
using System.Text.Json;
using System.Threading.Tasks;
namespace Cpm.Web.Api.Middlewares
{
public class RequestResponseLoggerMiddleware
{
private readonly RequestDelegate _next;
private readonly RequestResponseLoggerOption _options;
private readonly IRequestResponseLogger _logger;
public RequestResponseLoggerMiddleware
(RequestDelegate next, IOptions<RequestResponseLoggerOption> options,
IRequestResponseLogger logger)
{
_next = next;
_options = options.Value;
_logger = logger;
}
public async Task InvokeAsync(HttpContext httpContext,
IRequestResponseLogModelCreator logCreator)
{
RequestResponseLogModel log = logCreator.LogModel;
if (_options == null || !_options.IsEnabled)
{
await _next(httpContext);
return;
}
log.RequestDateTimeUtc = DateTime.UtcNow;
HttpRequest request = httpContext.Request;
log.LogId = Guid.NewGuid().ToString();
log.TraceId = httpContext.TraceIdentifier;
var ip = request.HttpContext.Connection.RemoteIpAddress;
log.ClientIp = ip == null ? null : ip.ToString();
log.Node = _options.Name;
log.RequestMethod = request.Method;
log.RequestPath = request.Path;
log.RequestQuery = request.QueryString.ToString();
log.RequestQueries = FormatQueries(request.QueryString.ToString());
log.RequestHeaders = FormatHeaders(request.Headers);
log.RequestBody = await ReadBodyFromRequest(request);
log.RequestScheme = request.Scheme;
log.RequestHost = request.Host.ToString();
log.RequestContentType = request.ContentType;
HttpResponse response = httpContext.Response;
var originalResponseBody = response.Body;
using var newResponseBody = new MemoryStream();
response.Body = newResponseBody;
try
{
await _next(httpContext);
}
catch (Exception exception)
{
LogError(log, exception);
}
newResponseBody.Seek(0, SeekOrigin.Begin);
var responseBodyText =
await new StreamReader(response.Body).ReadToEndAsync();
newResponseBody.Seek(0, SeekOrigin.Begin);
await newResponseBody.CopyToAsync(originalResponseBody);
log.ResponseContentType = response.ContentType;
log.ResponseStatus = response.StatusCode.ToString();
log.ResponseHeaders = FormatHeaders(response.Headers);
log.ResponseBody = responseBodyText;
log.ResponseDateTimeUtc = DateTime.UtcNow;
var contextFeature =
httpContext.Features.Get<IExceptionHandlerPathFeature>();
if (contextFeature != null && contextFeature.Error != null)
{
Exception exception = contextFeature.Error;
LogError(log, exception);
}
_logger.Log(logCreator);
}
private void LogError(RequestResponseLogModel log, Exception exception)
{
log.ExceptionMessage = exception.Message;
log.ExceptionStackTrace = exception.StackTrace;
}
private Dictionary<string, string> FormatHeaders(IHeaderDictionary headers)
{
Dictionary<string, string> pairs = new Dictionary<string, string>();
foreach (var header in headers)
{
pairs.Add(header.Key, header.Value);
}
return pairs;
}
private List<KeyValuePair<string, string>> FormatQueries(string queryString)
{
List<KeyValuePair<string, string>> pairs =
new List<KeyValuePair<string, string>>();
string key, value;
foreach (var query in queryString.TrimStart('?').Split("&"))
{
var items = query.Split("=");
key = items.Count() >= 1 ? items[0] : string.Empty;
value = items.Count() >= 2 ? items[1] : string.Empty;
if (!String.IsNullOrEmpty(key))
{
pairs.Add(new KeyValuePair<string, string>(key, value));
}
}
return pairs;
}
private async Task<string> ReadBodyFromRequest(HttpRequest request)
{
request.EnableBuffering();
using var streamReader = new StreamReader(request.Body, leaveOpen: true);
var requestBody = await streamReader.ReadToEndAsync();
request.Body.Position = 0;
return requestBody;
}
}
}
To access the log model, we need to get IRequestResponseLogModelCreator
, which will be injected as scoped. This injection will not work for the contractor. So we need to use this in the method InvokeAsync(HttpContext httpContext, IRequestResponseLogModelCreator logCreator)
.
Singletone injections only work at the constructor level for middleware. In middleware, usage of injection at the constructor level is very common. Even in the example, we are using injected IOptions<RequestResponseLoggerOption> options
and IRequestResponseLogger logger.
We can uncomment this line and check log JSON string
:
Filters
These filters are optional. In our case, we are using two filters to assign a few values to the log model. It is to demonstrate that we can even set additional log information from filters or controllers if needed. Same as the middleware IRequestResponseLogModelCreator
will not be injectable at the constructor. That's why we are using context.RequestServices.GetService<IRequestResponseLogModelCreator>()
to get the injected model.
RequestResponseLoggerActionFilter
is assigning RequestDateTimeUtcActionLevel
and ResponseDateTimeUtcActionLevel
to calculate action level execution time.
using Cpm.Web.Api.Middlewares;
using Microsoft.AspNetCore.Mvc.Filters;
using System;
using System.Diagnostics;
namespace Cpm.Web.Api.Filters
{
[AttributeUsage(validOn: AttributeTargets.Class | AttributeTargets.Method)]
public class RequestResponseLoggerActionFilter : Attribute, IActionFilter
{
private RequestResponseLogModel GetLogModel(HttpContext context)
{
return context.RequestServices.GetService
<IRequestResponseLogModelCreator>().LogModel;
}
public void OnActionExecuting(ActionExecutingContext context)
{
var model = GetLogModel(context.HttpContext);
model.RequestDateTimeUtcActionLevel = DateTime.UtcNow;
}
public void OnActionExecuted(ActionExecutedContext context)
{
var model = GetLogModel(context.HttpContext);
model.ResponseDateTimeUtcActionLevel = DateTime.UtcNow;
}
}
}
RequestResponseLoggerErrorFilter
assigning IsExceptionActionLevel
to track if the error is at the action level or at somewhere else. In application, we may get into a scenario where controller actions are executed without any error, but face errors at other middleware or after processors.
using Cpm.Web.Api.Middlewares;
using Microsoft.AspNetCore.Mvc.Filters;
using System;
using System.Diagnostics;
namespace Cpm.Web.Api.Filters
{
[AttributeUsage(validOn: AttributeTargets.Class | AttributeTargets.Method)]
public class RequestResponseLoggerErrorFilter : Attribute, IExceptionFilter
{
private RequestResponseLogModel GetLogModel(HttpContext context)
{
return context.RequestServices.GetService
<IRequestResponseLogModelCreator>().LogModel;
}
public void OnException(ExceptionContext context)
{
var model = GetLogModel(context.HttpContext);
model.IsExceptionActionLevel = true;
if (model.ResponseDateTimeUtcActionLevel == null)
{
model.ResponseDateTimeUtcActionLevel = DateTime.UtcNow;
}
}
}
}
Using Middleware/Filter
Let's add the middleware, filter, and dependency injections in Startup.cs or in the bootstrap file.
Inside void ConfigureServices(IServiceCollection services)
:
services.AddOptions<RequestResponseLoggerOption>().Bind
(Configuration.GetSection("RequestResponseLogger")).ValidateDataAnnotations();
services.AddSingleton<IRequestResponseLogger, RequestResponseLogger>();
services.AddScoped<IRequestResponseLogModelCreator, RequestResponseLogModelCreator>();
services.AddMvc(options =>
{
options.Filters.Add(new RequestResponseLoggerActionFilter());
options.Filters.Add(new RequestResponseLoggerErrorFilter());
});
and in void Configure(IApplicationBuilder app, IWebHostEnvironment env)
:
app.UseMiddleware<RequestResponseLoggerMiddleware>();
The full Startup.cs or in the bootstrap file:
using Cpm.Web.Api.Filters;
using Cpm.Web.Api.Middlewares;
using Microsoft.AspNetCore.Diagnostics;
using Microsoft.OpenApi.Models;
namespace Cpm.Web.Api
{
public class Startup
{
public Startup(IConfiguration configuration)
{
Configuration = configuration;
}
public IConfiguration Configuration { get; }
public void ConfigureServices(IServiceCollection services)
{
services.AddControllers();
services.AddSwaggerGen(c =>
{
c.SwaggerDoc("v1", new OpenApiInfo
{ Title = "Cpm.Web.Api", Version = "v1" });
});
services.AddOptions<RequestResponseLoggerOption>().Bind
(Configuration.GetSection("RequestResponseLogger")).ValidateDataAnnotations();
services.AddSingleton<IRequestResponseLogger, RequestResponseLogger>();
services.AddScoped<IRequestResponseLogModelCreator,
RequestResponseLogModelCreator>();
services.AddMvc(options =>
{
options.Filters.Add(new RequestResponseLoggerActionFilter());
options.Filters.Add(new RequestResponseLoggerErrorFilter());
});
}
public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
if (env.IsDevelopment())
{
app.UseDeveloperExceptionPage();
app.UseSwagger();
app.UseSwaggerUI(c => c.SwaggerEndpoint("/swagger/v1/swagger.json",
"Cpm.Web.Api v1"));
}
app.UseMiddleware<RequestResponseLoggerMiddleware>();
app.UseExceptionHandler(c => c.Run(async context =>
{
var exception = context.Features
.Get<IExceptionHandlerPathFeature>()
.Error;
var response = new { details = "An error occurred" };
await context.Response.WriteAsJsonAsync(response);
}));
app.UseHttpsRedirection();
app.UseRouting();
app.UseAuthorization();
app.UseEndpoints(endpoints =>
{
endpoints.MapControllers();
});
}
}
}
Testing the Code
Run the web application.
Curl
url -X POST "https://localhost:7178/api/Hello/Details/1?eventId=100&eventName=name"
-H "accept: text/plain" -H "Content-Type: application/json" -d "{\"value\":\"here\"}"
Log Sample
{
"LogId":"0b51f509-c8a0-471d-bd79-b3161afb19e7",
"Node":"Cpm.Web.Api",
"ClientIp":"::1",
"TraceId":"0HMJ8HNMBP84I:00000007",
"RequestDateTimeUtc":"2022-07-18T07:20:15.9655886Z",
"RequestDateTimeUtcActionLevel":"2022-07-18T07:20:16.0408026Z",
"RequestPath":"/api/Hello/Details/1",
"RequestQuery":"?eventId=100&eventName=name",
"RequestQueries":[
{
"Key":"eventId",
"Value":"100"
},
{
"Key":"eventName",
"Value":"name"
}
],
"RequestMethod":"POST",
"RequestScheme":"https",
"RequestHost":"localhost:7178",
"RequestHeaders":{
"Accept":"text/plain",
"Host":"localhost:7178",
"User-Agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0 Safari/537.36",
":method":"POST",
"Accept-Encoding":"gzip, deflate, br",
"Accept-Language":"en-GB,en-US;q=0.9,en;q=0.8",
"Content-Type":"application/json",
"Cookie":"ai_user=tfFT6|2022-02-03T10:19:20.897Z,
_ga=GA1.1.1007006786.1656487658,.AspNetCore.Culture=c%3Den%7Cuic%3Den,
ai_session=qUyl5|1658128684507|1658128810611.5",
"Origin":"https://localhost:7178",
"Referer":"https://localhost:7178/swagger/index.html",
"Content-Length":"16",
"sec-ch-ua":"\".Not/A)Brand\";v=\"99\", \"Google Chrome\";v=\"103\",
\"Chromium\";v=\"103\"",
"sec-ch-ua-mobile":"?0",
"sec-ch-ua-platform":"\"Windows\"",
"sec-fetch-site":"same-origin",
"sec-fetch-mode":"cors",
"sec-fetch-dest":"empty"
},
"RequestBody":"{\"value\":\"here\"}",
"RequestContentType":"application/json",
"ResponseDateTimeUtc":"2022-07-18T07:20:16.0454527Z",
"ResponseDateTimeUtcActionLevel":"2022-07-18T07:20:16.0411664Z",
"ResponseStatus":"200",
"ResponseHeaders":{
"Content-Type":"application/json; charset=utf-8",
"Date":"Mon, 18 Jul 2022 07:20:15 GMT",
"Server":"Kestrel"
},
"ResponseBody":"{\"value\":\"here\"}",
"ResponseContentType":"application/json; charset=utf-8",
"IsExceptionActionLevel":null,
"ExceptionMessage":null,
"ExceptionStackTrace":null
}
References
Request Response Log
IP
Observability
About Code Sample
- Visual Studio 2022 Solution
- ASP.NET 6
- This example is also tested in 5, 3.1
History
- 29th July, 2022: Initial version
This member has not yet provided a Biography. Assume it's interesting and varied, and probably something to do with programming.