Add handler timing pipeline

Component: NServiceBus
NuGet Package NServiceBus (6.x)

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 so as to sometimes trigger the threshold.

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

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()
                .ConfigureAwait(false);
        }
        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

public class HandlerTimerFeature :
    Feature
{
    internal HandlerTimerFeature()
    {
        EnableByDefault();
    }

    protected override void Setup(FeatureConfigurationContext context)
    {
        context.Pipeline.Register<Registration>();
    }

    public class Registration :
        RegisterStep
    {
        public Registration()
            : base(
                stepId: "HandlerTimer",
                behavior: typeof(HandlerTimerBehavior),
                description: "Logs a warning if a handler take more than a specified time")
        {
        }
    }
}

Related Articles


Last modified