How to measure invocation time of "Handle" method in NServiceBus?

Question

I need to measure invocation time of Handle method in every instance of IHandleMessages<> interface. I tried to use Interceptor of Castle Windsor,

public class NsbHandlerMeasurementInterceptor : IInterceptor
{
    public void Intercept(IInvocation invocation)
    {
        if (invocation.Method.Name == ExpressionExtender.GetMethodName<IHandleMessages<DummyType>>(b => b.Handle(null)))
        {
            Stopwatch stopwatch = new Stopwatch();
            stopwatch.Start();

            invocation.Proceed();

            stopwatch.Stop();

            // save stopwatch.ElapsedMilliseconds value
        }
        else
        {
            invocation.Proceed();
        }
    }
}

with installation code:

container.Register(Component.For<NsbHandlerMeasurementInterceptor>());
container.Kernel.ComponentModelBuilder.AddContributor(new NsbWindsorModelConstructionContributor());

public class NsbWindsorModelConstructionContributor : IContributeComponentModelConstruction
{
    public void ProcessModel(global::Castle.MicroKernel.IKernel kernel, global::Castle.Core.ComponentModel model)
    {
        if (model.Services.Any(s => s.ImplementsGenericInterface(typeof(IHandleMessages<>))))
        {
            model.Interceptors.AddIfNotInCollection(new InterceptorReference(typeof(NsbHandlerMeasurementInterceptor)));    
        }
    }
}

but from that moment Handle method is not firing.

I know about performance counters in NSB, but I need more specific, type-oriented measurements. Is it possible and achievable?

Answer 1

To measure all there is indeed performance counter but if that is not sufficient then you can create your own step in the NServiceBus pipeline.

http://docs.particular.net/nservicebus/pipeline/customizing

Create a custom behavior by inheriting IBehavior<IncomingContext> and implement the interface. You now have access to the IncomingContext argument which contain information about the types.

Take a look at the implementation of the InvokeHandlersBehavior behavior. This behavior invokes the actual handler and probably want to wrap that.

https://github.com/Particular/NServiceBus/blob/5.2.0/src/NServiceBus.Core/Unicast/Behaviors/InvokeHandlersBehavior.cs

class InvokeHandlersBehavior : IBehavior<IncomingContext>
{
    public void Invoke(IncomingContext context, Action next)
    {
        ActiveSagaInstance saga;

        if (context.TryGet(out saga) && saga.NotFound && saga.SagaType == context.MessageHandler.Instance.GetType())
        {
            next();
            return;
        }

        var messageHandler = context.MessageHandler;

        messageHandler.Invocation(messageHandler.Instance, context.IncomingLogicalMessage.Instance);
        next();
    }
}

You then need to register it so that it called included in the pipeline.

class NewStepInPipeline : RegisterStep
{
    public NewStepInPipeline()
        : base("NewStepInPipeline", typeof(SampleBehavior), "Logs a warning when processing takes too long")
    {
        // Optional: Specify where it needs to be invoked in the pipeline, for example InsertBefore or InsertAfter
        InsertBefore(WellKnownStep.InvokeHandlers);
    }
}

class NewStepInPipelineRegistration : INeedInitialization
{
    public void Customize(BusConfiguration busConfiguration)
    {
        // Register the new step in the pipeline
        busConfiguration.Pipeline.Register<NewStepInPipeline>();
    }
}

Please note that this code requires v5. Check the Particular documentation website for help on other versions.