Logging is one of the most essential components in an application. An application once moved to production still needs maintenance and monitoring for any uncovered bugs and runtime errors and a good logging mechanism implemented with essential attributes being logged can be a lot helpful in understanding the issues better.
Similarly when building an API for any application, it is indeed necessary to build an underlying logging system which can put up nice insights for every request received.
In this article, let’s discuss one such scenarios which we face in real-world while building a robust logging system for an API : Logging an overall request-response cycle.
Introduction – Request Response Lifecycle
In one of the applications I was working on, the client was interested in assessing any incoming request that is hit on to the API and wanted to see the entire trace of the request being processed. This included the response that has been generated by the API for the request.
This entire flow beginning from the origin of the request till the last mile it travels out of the system with a response forms a request-response cycle, and my task was to build a logging system that captures every single request and corresponding response for that request and log it into a back office accessible by the client maintenance team.
This of course implied that any sensitive information is either to be masked or dropped off the logs, but the point I’m trying to make is the priceless insights it results in an API. And this needed to be done in dotnet core, let’s see how we can achieve this.
Intercepting the Pipeline through Middlewares
One of the most interesting things I feel dotnet core has been provided with is the concept of Middlewares. Each middleware component when hooked up to the request pipeline, can have access to the context object which can provide information about the request in question and the response in action.
Every request needs to pass through the Middleware components in place, before reaching the controller or the endpoint and has to pass through the same components in return direction.
This makes these components ideal for things such as Authorization, Logging and others to name a few. But handling request and response objects involve handling of Streams, and can be tad difficult if not taken proper care of.
Implementing this Middleware with an Example
For our example, let’s take the application of ReadersApi we are already familiar. Now for the API application, we are interested in logging in all the requests and responses which are served by our API. And we’d like to store the logs collected to a LoggerStore, say a database. Let’s construct a typical Log model which can be as shown below:
namespace ReadersApi.Providers
{
public class Log
{
public string Path { get; set; }
public string QueryString { get; set; }
public string Method { get; set; }
public string Payload { get; set; }
public string Response { get; set; }
public string ResponseCode { get; set; }
public DateTime RequestedOn { get; set; }
public DateTime RespondedOn { get; set; }
public bool IsSuccessStatusCode { get; set; }
}
}
Now let’s build a domain logic separation for Logger, which is solely responsible for all the transactions on the Log objects. For this, we shall create a Repository class with its interface specification.
A Repository class is a separation of the domain logic from the controller class, which we can use to create an abstraction. Thereby we can make the controllers more testable and cohesive.
namespace ReadersApi.Providers
{
public interface ILoggerRepo
{
void AddToLogs(Log log);
List<Log> GetAllLogs();
}
public class LoggerRepo : ILoggerRepo
{
public void AddToLogs(Log log)
{
LoggerStore.Logs.Add(log);
}
public List<Log> GetAllLogs()
{
return LoggerStore.Logs;
}
}
public class LoggerStore
{
public static List<Log> Logs = new List<Log>();
}
}
For keeping things simple, let’s push all the logs generated into a static LoggerStore which has a List for maintaining the logs.
In a real-world scenario, the LoggerStore instance would be replaced by an actual DatabaseContext provided by an ORM such as EntityFramework Core using which we can push to the database.
The LoggerRepo class which implements the ILoggerRepo interface contains two methods: one which adds a Log object to the store and one which returns all the logs stored.
Let’s also add an endpoint for the generated Logs be retrieved.
namespace ReadersApi.Controllers
{
[Route("api/[controller]")]
[ApiController]
public class LoggerController : ControllerBase
{
ILoggerRepo repo;
public LoggerController(ILoggerRepo repo)
{
this.repo = repo;
}
[HttpGet]
[Route("logs")]
public List<Log> GetAllLogs()
{
return repo.GetAllLogs();
}
}
}
Now here comes the most important part. Let’s create a class which is to be hooked up as a middleware to the pipeline. Let’s call the class as Logger.
namespace ReadersApi.Middlewares
{
public class Logger
{
RequestDelegate next;
public Logger(RequestDelegate next)
{
this.next = next;
}
public async Task InvokeAsync(HttpContext context, ILoggerRepo repo)
{
//Request handling comes here
}
}
}
And is hooked to the pipeline via the Startup class under the Configure() method.
namespace ReadersApi
{
public class Startup
{
public Startup(IConfiguration configuration)
{
Configuration = configuration;
}
public IConfiguration Configuration { get; }
// This method gets called by the runtime.
// Use this method to add services to the container.
public void ConfigureServices(IServiceCollection services)
{
/* other code */
services.AddSingleton<ILoggerRepo, LoggerRepo>();
/* other code */
}
// This method gets called by the runtime.
// Use this method to configure the HTTP request pipeline.
public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
/* other code */
app.UseMiddleware<Logger>();
/* other code */
}
}
}
Logging Incoming HTTP Request
The incoming request attributes can be read as below:
// create a new log object
var log = new Log
{
Path = context.Request.Path,
Method = context.Request.Method,
QueryString = context.Request.QueryString.ToString()
};
// check if the Request is a POST call
// since we need to read from the body
if (context.Request.Method == "POST")
{
context.Request.EnableBuffering();
var body = await new StreamReader(context.Request.Body)
.ReadToEndAsync();
context.Request.Body.Position = 0;
log.Payload = body;
}
log.RequestedOn = DateTime.Now;
await next.Invoke(context);
We would take in the context object supplied within the Invoke method of the middleware class and then examine the Request property of the HttpContext object. The POST calls need to be taken special care of: since we need to read from the Request body which is a stream.
Streams can be read only once if not enabled Seek(). Hence we enable buffering on the Request, and then read till the end of the body stream. We finally reset the Request body stream to 0 so that it can be read again by the actual endpoint.
The read string is saved on to the Payload attribute. We then send the Request off to further processing by calling the next.Invoke() method with the HttpContext as a parameter. That solves the Request part. Now remains the Response.
Logging outgoing HTTP Response
We cannot read the Response straight away like we do on the Request, since it will not be available until the processing is done and the next.Invoke() completes its execution. Hence we keep track of the Response by assigning a MemoryStream onto it.
Since this stream needs to be disposed properly to avoid memory issues we wrap it up under a using block. The Response is written by the endpoint handler onto the memory stream instance we pass from here (instead of the actual response body) and so we copy the content back to the Response body once the stream is read.
using (Stream originalRequest = context.Response.Body)
{
try
{
using (var memStream = new MemoryStream())
{
context.Response.Body = memStream;
// All the Request processing as described above
// happens from here.
// Response handling starts from here
// set the pointer to the beginning of the
// memory stream to read
memStream.Position = 0;
// read the memory stream till the end
var response = await new StreamReader(memStream)
.ReadToEndAsync();
// write the response to the log object
log.Response = response;
log.ResponseCode = context.Response.StatusCode.ToString();
log.IsSuccessStatusCode = (
context.Response.StatusCode == 200 ||
context.Response.StatusCode == 201);
log.RespondedOn = DateTime.Now;
// add the log object to the logger stream
// via the Repo instance injected
repo.AddToLogs(log);
// since we have read till the end of the stream,
// reset it onto the first position
memStream.Position = 0;
// now copy the content of the temporary memory
// stream we have passed to the actual response body
// which will carry the response out.
await memStream.CopyToAsync(originalRequest);
}
}
catch (Exception ex)
{
Console.WriteLine(ex);
}
finally
{
// assign the response body to the actual context
context.Response.Body = originalRequest;
}
}
Found this article helpful? Please consider supporting!
Conclusion
Logging is indeed an important aspect of application development and maintenance. In dotnetcore, we can log any HTTP Request and Response using the built-in Middleware architecture. The concept is simple, you read the request stream and pass it on – read the response stream and write it back. Simple!
What do you think of this approach? Please do let me know down below!
Found this article helpful? Please consider supporting!
