How to detect slow responses in Umbraco API?
Introduction
In this short article, I am going to present a very simple technique to detect every slow response coming from UmbracoApiController using ActionFilterAttribute.
It can be useful when we want to:
Concept outline
public sealed class UmbracoApiPerformanceTrackingAttribute : ActionFilterAttribute
{
public override void OnActionExecuting(HttpActionContext actionContext)
{
//We start measuring the request
base.OnActionExecuting(actionContext);
}
public override Task OnActionExecutedAsync(HttpActionExecutedContext actionExecutedContext, CancellationToken cancellationToken)
{
//We finish the measurement and log the information when the request is slow
return base.OnActionExecutedAsync(actionExecutedContext, cancellationToken);
}
}As you can see - we should create UmbracoApiPerformanceTrackingAttribute class and intercept every action executing/executed events.
Additional ingredients
Inside the filter we should put the logic and add a few additional components:
ProfilingModeEnabled flag allows you to turn the profiler on and off as needed.
SlowResponseMinTimeInMilliseconds defines the time of slow request because we want to log only suspicious requests.
public sealed class UmbracoApiPerformanceTrackingAttribute : ActionFilterAttribute
{
private const string StopWatchCacheKey = "UmbracoPerformanceTracking_Stopwatch";
public override void OnActionExecuting(HttpActionContext actionContext)
{
if (AppConfigProvider.ProfilingModeEnabled)
{
var stopwatch = Stopwatch.StartNew();
HttpContext.Current.Items[StopWatchCacheKey] = stopwatch;
}
base.OnActionExecuting(actionContext);
}
public override Task OnActionExecutedAsync(HttpActionExecutedContext actionExecutedContext, CancellationToken cancellationToken)
{
if (AppConfigProvider.ProfilingModeEnabled)
{
Stopwatch stopwatch = (Stopwatch)HttpContext.Current.Items[StopWatchCacheKey];
stopwatch.Stop();
if (stopwatch.ElapsedMilliseconds >= AppConfigProvider.SlowResponseMinTimeInMilliseconds)
{
string bodyDetails = string.Empty;
if (actionExecutedContext.Request.Method == HttpMethod.Post)
{
StringBuilder bodyBuilder = new StringBuilder();
foreach (var arg in actionExecutedContext.ActionContext.ActionArguments)
{
bodyBuilder.Append(arg.ToJsonString());
}
bodyDetails = $"Body: {bodyBuilder}";
}
Current.Logger.Warn(typeof(UmbracoCustomLoggingAttribute), $"SLOW RESPONSE (took more than {AppConfigProvider.SlowResponseMinTimeInMilliseconds}): {stopwatch.ElapsedMilliseconds} [ms] - {actionExecutedContext.Request.Method} {actionExecutedContext.Request.RequestUri} {bodyDetails}");
}
}
return base.OnActionExecutedAsync(actionExecutedContext, cancellationToken);
}
}Now, you should be able to decorate UmbracoApiController with new filter as follows:
[UmbracoApiPerformanceTracking]
public class BaseUmbracoApiController : UmbracoApiController
{
}Configure appropriate log level
In this case, we will set the level as "Warning".
When using serilog:
<?xml version="1.0" encoding="utf-8" ?>
<configuration>
<appSettings>
<!-- VALID Values: Verbose, Debug, Information, Warning, Error, Fatal -->
<add key="serilog:minimum-level" value="Warning" />
</appSettings>
</configuration>And that's it!
I hope you find this concept useful and you can adapt it to your needs.
Happy Umbraco performance tracking!😉💨
References: