Have logging ever irritated you?
If yes, then you’re definitely not alone! Often when I work with Web APIs in C#, logging tends to take up a lot of space, making the code quickly look “ugly.” I like to log what parameters the method is called with, which controller the method is in, etc. Therefore, a method often looks like this for me, in a simplified way:
[HttpGet("{id}")]
public ActionResult<WeatherForecast> Get(int id)
{
_logger.LogInformation($"Starting to find weather forecast with ID: {id}");
{ ... }
_logger.LogInformation($"Weather forecast with id {id} is fetched");
return new WeatherForecast();
}
Output
Starting to find weather forecast with ID: 234
Weather forecast with id 234 is fetched
I definitely don’t find it visually appealing, and it contributes to my classes sometimes becoming extremely long. Therefore, I’ve been thinking that it should be possible to make it easier and also more elegant. It got me thinking about how you can do so many cool things with custom attributes, so why not create some nice logging with an attribute?
And, as so many times before, almost anything is possible with C#; it’s mainly just a matter of having the idea for it. So what I’ve come up with is just an attribute that inherits from IActionFilter, since IActionFilter already implements OnActionExecuted and OnActionExecuting.
[ActionLogger] // <-- Custom attribute
[HttpGet("{id}")]
public ActionResult<WeatherForecast> Get(int id)
{
return new WeatherForecast();
}
Output
[GET][WeatherForecastController][/WeatherForecast/234] Executing with parameters: [id, 234]
[GET][WeatherForecastController][/WeatherForecast/234] Executed
How did I go about implementing it then?
public class ActionLoggerAttribute : Attribute, IActionFilter
{
public void OnActionExecuted(ActionExecutedContext context)
{
ILogger? logger = GetLogger(context, context.Controller.GetType());
var httpMethod = context.HttpContext.Request.Method;
var routeUrl = context.HttpContext.Request.Path;
var controllerName = context.Controller.GetType().Name;
if (logger == null)
{
return;
}
logger.LogInformation($"[{httpMethod}][{controllerName}][{routeUrl}] Executed");
}
public void OnActionExecuting(ActionExecutingContext context)
{
ILogger? logger = GetLogger(context, context.Controller.GetType());
var parameters = context.ActionArguments;
var httpMethod = context.HttpContext.Request.Method;
var routeUrl = context.HttpContext.Request.Path;
var controllerName = context.Controller.GetType().Name;
if (logger == null)
{
return;
}
string baseMessage = $"[{httpMethod}][{controllerName}][{routeUrl}] Executing";
switch (httpMethod)
{
case "POST":
// Get the type of body content
var bodyType = context.ActionDescriptor.Parameters
.FirstOrDefault(p => p.BindingInfo?.BindingSource?.DisplayName == "Body")
?.Name;
// Get the value of bodytype
var bodyContent = bodyType != null ? JsonSerializer.Serialize(parameters[bodyType]) : null;
if (bodyContent != null)
{
logger.LogInformation($"{baseMessage} with body content: {bodyContent}");
break;
}
logger.LogInformation($"{baseMessage} without body content");
break;
case "GET":
if (parameters.Count > 0)
{
logger.LogInformation($"{baseMessage} with parameters: {string.Join(", ", parameters)}"
break;
}
logger.LogInformation($"{baseMessage} without parameters");
break;
default:
logger.LogInformation($"{baseMessage} with parameters: {string.Join(", ", parameters)}");
break;
}
}
private ILogger<T>? GetLogger<T>(FilterContext context, T type)
{
return (ILogger<T>?)context.HttpContext.RequestServices.GetService(typeof(ILogger<T>));
}
}
As mentioned, I simply created an attribute that inherits from IActionFilter, allowing me to override what should happen in OnActionExecuted and OnActionExecuting. In the specific code I’ve written for my test to see what’s possible, I might have gone a bit overkill – but then again, it’s just to test the limits. I don’t think in a “real” setup you’d want to log the entire received request.
Best practice?
I know it’s not the best practice or the least resource-intensive way to log, but regardless, I’m thinking of using this type of attribute in some future projects because it’s easy, quick, and doesn’t clutter the code. Often, for me, it’s just as good, as it doesn’t necessarily matter much for the solutions I create whether it takes 40ms or 80ms, but rather how quickly I can pinpoint the root cause when an error occurs.
Jeppe Spanggaard
A passionate software developer. I love to build software that makes a difference!