Add handler timing pipeline

Component: NServiceBus
NuGet Package: NServiceBus (7.x)


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 :
    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);

The Behavior

class HandlerTimerBehavior :
    static ILog log = LogManager.GetLogger<HandlerTimerBehavior>();

    public override async Task Invoke(IInvokeHandlerContext context, Func<Task> next)
        var stopwatch = Stopwatch.StartNew();
            await next()
            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");

Related Articles

Last modified