Bug: Safe handle has been closed (NServiceBus / NancyFX)

Question

I've been debugging for days trying to find the root cause and it seems that it is caused by simply sending two messages.

public class HomeModule : NancyModule
{
    public HomeModule(IBus bus)
    {
        Get["/"] = _ => 
        {
            bus.Send<Command1>(m => { m.Id = "WHATEVER"; });
            return "OK";
        };
    }
}

public class Command1 : ICommand
{
    public string Id { get; set; }
}

public class Command2 : ICommand
{
    public string Id { get; set; }
}

public class Handler1 : IHandleMessages<Command1>
{
    public IBus Bus { get; set; }

    public void Handle(Command1 message)
    {
        Bus.Send<Command2>(m => { m.Id = message.Id; });
    }
}

public class Handler2 : IHandleMessages<Command2>
{
    public IBus Bus { get; set; }

    public void Handle(Command2 message)
    {

    }
}

public class Bootstrapper : DefaultNancyBootstrapper
{
    protected override void ApplicationStartup(Nancy.TinyIoc.TinyIoCContainer container, Nancy.Bootstrapper.IPipelines pipelines)
    {
        base.ApplicationStartup(container, pipelines);

        LogManager.Use<DefaultFactory>().Directory(container.Resolve<IRootPathProvider>().GetRootPath());

        var configuration = new BusConfiguration();
        configuration.EndpointName("MyEndpoint");
        configuration.DisableFeature<NServiceBus.Features.SecondLevelRetries>(); // TODO
        if (Debugger.IsAttached) configuration.EnableInstallers();
        configuration.UsePersistence<InMemoryPersistence>();

        var bus = Bus.Create(configuration).Start();

        container.Register<IBus>(bus);
    }
}

Gives me error:

Key Value CorrId a539e440-0b7a-4283-a20a-a472006da636\0 NServiceBus.ContentType text/xml NServiceBus.ConversationId 2b38fa53-749b-43e4-aa0f-a472006da63a NServiceBus.CorrelationId a539e440-0b7a-4283-a20a-a472006da636 NServiceBus.EnclosedMessageTypes Command1, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null NServiceBus.ExceptionInfo.ExceptionType System.ObjectDisposedException NServiceBus.ExceptionInfo.HelpLink
NServiceBus.ExceptionInfo.Message Safe handle has been closed NServiceBus.ExceptionInfo.Source mscorlib NServiceBus.ExceptionInfo.StackTrace System.ObjectDisposedException: Safe handle has been closed at System.Runtime.InteropServices.SafeHandle.DangerousAddRef(Boolean& success) at System.StubHelpers.StubHelpers.SafeHandleAddRef(SafeHandle pHandle, Boolean& success) at Microsoft.Win32.Win32Native.GetTokenInformation(SafeTokenHandle TokenHandle, UInt32 TokenInformationClass, SafeLocalAllocHandle TokenInformation, UInt32 TokenInformationLength, UInt32& ReturnLength) at System.Security.Principal.WindowsIdentity.GetTokenInformation(SafeTokenHandle tokenHandle, TokenInformationClass tokenInformationClass) at System.Security.Principal.WindowsIdentity.get_User() at System.Security.Principal.WindowsIdentity.GetName() at System.Security.Principal.WindowsIdentity.get_Name() at NServiceBus.Impersonation.Windows.WindowsIdentityEnricher.MutateOutgoing(LogicalMessage logicalMessage, TransportMessage transportMessage) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Impersonation\Windows\WindowsIdentityEnricher.cs:line 16 at NServiceBus.MutateOutgoingPhysicalMessageBehavior.Invoke(OutgoingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\MessageMutator\MutateOutgoingPhysicalMessageBehavior.cs:line 12 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.SerializeMessagesBehavior.Invoke(OutgoingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\SerializeMessagesBehavior.cs:line 38 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.CreatePhysicalMessageBehavior.Invoke(OutgoingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\CreatePhysicalMessageBehavior.cs:line 58 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.PopulateAutoCorrelationHeadersForRepliesBehavior.Invoke(OutgoingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Sagas\PopulateAutoCorrelationHeadersForRepliesBehavior.cs:line 46 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.MutateOutgoingMessageBehavior.Invoke(OutgoingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\MessageMutator\MutateOutgoingMessageBehavior.cs:line 28 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.SendValidatorBehavior.Invoke(OutgoingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\SendValidatorBehavior.cs:line 20 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.Invoke() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 52 at NServiceBus.Pipeline.PipelineExecutor.Execute[T](BehaviorChain1 pipelineAction, T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 129 at NServiceBus.Pipeline.PipelineExecutor.InvokePipeline[TContext](IEnumerable1 behaviors, TContext context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 85 at NServiceBus.Pipeline.PipelineExecutor.InvokeSendPipeline(DeliveryOptions deliveryOptions, LogicalMessage message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 114 at NServiceBus.Unicast.UnicastBus.InvokeSendPipeline(DeliveryOptions sendOptions, LogicalMessage message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\UnicastBus.cs:line 624 at NServiceBus.Unicast.UnicastBus.SendMessage(SendOptions sendOptions, LogicalMessage message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\UnicastBus.cs:line 610 at NServiceBus.Unicast.UnicastBus.Send[T](Action1 messageConstructor) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\UnicastBus.cs:line 455 at lambda_method(Closure , Object , Object ) at NServiceBus.Unicast.MessageHandlerRegistry.Invoke(Object handler, Object message, Dictionary2 dictionary) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\MessageHandlerRegistry.cs:line 126 at NServiceBus.Unicast.MessageHandlerRegistry.InvokeHandle(Object handler, Object message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\MessageHandlerRegistry.cs:line 84 at NServiceBus.LoadHandlersBehavior.b__1(Object handlerInstance, Object message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\LoadHandlersBehavior.cs:line 40 at NServiceBus.InvokeHandlersBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\InvokeHandlersBehavior.cs:line 24 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.SetCurrentMessageBeingHandledBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\SetCurrentMessageBeingHandledBehavior.cs:line 17 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.LoadHandlersBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\LoadHandlersBehavior.cs:line 45 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.ApplyIncomingMessageMutatorsBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\MessageMutator\ApplyIncomingMessageMutatorsBehavior.cs:line 23 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.ExecuteLogicalMessagesBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Messages\ExecuteLogicalMessagesBehavior.cs:line 24 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.CallbackInvocationBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\CallbackInvocationBehavior.cs:line 22 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.DeserializeLogicalMessagesBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Messages\DeserializeLogicalMessagesBehavior.cs:line 47 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.ApplyIncomingTransportMessageMutatorsBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\MessageMutator\ApplyIncomingTransportMessageMutatorsBehavior.cs:line 20 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.SubscriptionReceiverBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Subscriptions\MessageDrivenSubscriptions\SubscriptionReceiverBehavior.cs:line 31 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.UnitOfWorkBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\UnitOfWork\UnitOfWorkBehavior.cs:line 42 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.ChildContainerBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Behaviors\ChildContainerBehavior.cs:line 17 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.ProcessingStatisticsBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Monitoring\ProcessingStatisticsBehavior.cs:line 23 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass5.b__2() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 94 at NServiceBus.AuditBehavior.Invoke(IncomingContext context, Action next) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Audit\AuditBehavior.cs:line 20 at NServiceBus.BehaviorChain1.InvokeNext(T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.Invoke() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 52 at NServiceBus.Pipeline.PipelineExecutor.Execute[T](BehaviorChain1 pipelineAction, T context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 129 at NServiceBus.Pipeline.PipelineExecutor.InvokePipeline[TContext](IEnumerable1 behaviors, TContext context) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 85 at NServiceBus.Pipeline.PipelineExecutor.InvokeReceivePhysicalMessagePipeline() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 102 at NServiceBus.Unicast.UnicastBus.TransportMessageReceived(Object sender, TransportMessageReceivedEventArgs e) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\UnicastBus.cs:line 826 at NServiceBus.Unicast.Transport.TransportReceiver.OnTransportMessageReceived(TransportMessage msg) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Transport\TransportReceiver.cs:line 411 at NServiceBus.Unicast.Transport.TransportReceiver.ProcessMessage(TransportMessage message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Transport\TransportReceiver.cs:line 344 at NServiceBus.Unicast.Transport.TransportReceiver.TryProcess(TransportMessage message) in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Unicast\Transport\TransportReceiver.cs:line 228 at NServiceBus.Transports.Msmq.MsmqDequeueStrategy.Action() in c:\BuildAgent\work\3206e2123f54fce4\src\NServiceBus.Core\Transports\Msmq\MsmqDequeueStrategy.cs:line 266

The problem only occurs when I enable Windows Authentication and disable Anonymous.

Answer 1

NServiceBus version 5.1+ fixes this issue.
This issue has been reported before in https://groups.google.com/d/msg/particularsoftware/lA7qYOMrqbU/XXs3SfAGcYAJ

Answer 2

As I mentioned in the comments, this looks like a bug specifically in NancyFX.

The problem is that the proposed WindowsIdentityEnricher only checks for null. Since Thread.CurrentPrincipal exists the first check passes, but the Name has a Disposed error.

I put a watch on Thread.CurrentPrincipal.Name. It fails somewhere in between MsmqMessageSender.Send() and MsmqDequeueStrategy.OnPeekCompleted(), which suggests to me that it is a bug outside of NService.

As a work around I added a new mutator to re-populate the principle.

public class PrincipalEnricher : IMutateOutgoingTransportMessages
{
    public void MutateOutgoing(LogicalMessage logicalMessage, TransportMessage transportMessage)
    {
        Thread.CurrentPrincipal = new WindowsPrincipal(WindowsIdentity.GetCurrent());
    }
}

I am not familiar enough with NService to know if it is deterministically called before the WindowsIdentityEnricher mutator or just a coincidence.

Hope this helps someone.

PS. By coincidence I notice the same error in MVC if I start the bus and send a message in the same controller, and not in the Global class.