Introduction
This sample leverages the pipeline to add timing to handlers. It injects a Behavior into the pipeline before a handler is executed and uses a Stopwatch to measure how long a handler takes and then log a warning if the handler execution exceeds a specified threshold.
The Handler
The handler sleeps for a random amount of time it will trigger the threshold occasionally.
public class Handler1 :
IHandleMessages<Message>
{
static ILog log = LogManager.GetLogger<Handler1>();
static Random random = new Random();
public Task Handle(Message message, IMessageHandlerContext context)
{
var milliseconds = random.Next(100, 1000);
log.Info($"Message received going to Task.Delay({milliseconds}ms)");
return Task.Delay(milliseconds, context.CancellationToken);
}
}
The Behavior
class HandlerTimerBehavior :
Behavior<IInvokeHandlerContext>
{
static ILog log = LogManager.GetLogger<HandlerTimerBehavior>();
public override async Task Invoke(IInvokeHandlerContext context, Func<Task> next)
{
var stopwatch = Stopwatch.StartNew();
try
{
await next();
}
finally
{
var elapsedMilliseconds = stopwatch.ElapsedMilliseconds;
if (elapsedMilliseconds > 500)
{
var handlerName = context.MessageHandler.Instance.GetType().Name;
log.Warn($"{handlerName} took {elapsedMilliseconds}ms to process");
}
}
}
}
Configuring the Pipeline
endpointConfiguration.Pipeline.Register(typeof(HandlerTimerBehavior), "Logs a warning if a handler take more than a specified time");