Can NServiceBus publish to subscribers in the same AppDomain?

Question

I have a simple web site. In my API controller I am capturing a Command and Sending it to a Handler. This works perfectly. In the handler I do some processing, and then Publish an event. The event NEVER gets published. I cannot even begin to describe the list of changes I have done to get this working, all to no avail.

About the only thing I can see that is different between my app and any sample is that mine has the publisher and subscriber in the same assembly. At this point in time I don't see the need for having a separate NServiceBus process, although I will likely do that at some point.

Handler

public sealed class PortfoliosHandler : IHandleMessages<CreatePortfolioCommand>, IHandleMessages<PortfolioCreatedEvent>
{
    public void Handle(CreatePortfolioCommand message)
    {
        // Processing logic, this executes just fine

        Bus.Publish(new PortfolioCreatedEvent { Name = portfolio.Name });
    }

    public void Handle(PortfolioCreatedEvent message)
    {
        // This NEVER executes
    }
}

Config

<UnicastBusConfig ForwardReceivedMessagesTo="audit">
    <MessageEndpointMappings>
        <add Assembly="Project.Domain" Namespace="Project.Domain.PM.Commands" Endpoint="messagebus" />
        <add Assembly="Project.Domain" Namespace="Project.Domain.PM.Events" Endpoint="messagebus" />
    </MessageEndpointMappings>
</UnicastBusConfig>

Config Code

NServiceBus.Configure.Transactions.Enable();

var config = NServiceBus.Configure.With();

config = config
    .AutofacBuilder(container)
    .Log4Net(new DebugAppender {Threshold = Level.Warn})
    .UseTransport<Msmq>()
    .PurgeOnStartup(true)
    .UnicastBus()
    .LoadMessageHandlers()
    .RunHandlersUnderIncomingPrincipal(false)
    .InMemorySubscriptionStorage()
    .UseInMemoryTimeoutPersister();

var bus = config
    .CreateBus()
    .Start(() => Configure.Instance.ForInstallationOn<NServiceBus.Installation.Environments.Windows>()
                            .Install());

Not only does the event handler never fire, but no event message ever appears in the queues, and no record of it being published ever appears in the logs. It's almost as if I never sent it. Here are the log entries emitted by calling the Publish method above:

NServiceBus.Unicast.UnicastBus: 15:52:11,984 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Transports.Msmq.CorrelationIdMutatorForBackwardsCompatibilityWithV3
NServiceBus.Unicast.UnicastBus: 15:52:11,984 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Transports.Msmq.CorrelationIdMutatorForBackwardsCompatibilityWithV3
NServiceBus.Unicast.UnicastBus: 15:52:12,240 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Impersonation.Windows.WindowsIdentityEnricher
NServiceBus.Unicast.UnicastBus: 15:52:12,240 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Impersonation.Windows.WindowsIdentityEnricher
NServiceBus.Unicast.UnicastBus: 15:52:12,488 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Unicast.Monitoring.VersionMutator
NServiceBus.Unicast.UnicastBus: 15:52:12,488 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Unicast.Monitoring.VersionMutator
NServiceBus.Unicast.UnicastBus: 15:52:12,743 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Unicast.Monitoring.SentTimeMutator
NServiceBus.Unicast.UnicastBus: 15:52:12,743 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Unicast.Monitoring.SentTimeMutator
NServiceBus.Unicast.UnicastBus: 15:52:12,984 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Unicast.Monitoring.CausationMutator
NServiceBus.Unicast.UnicastBus: 15:52:12,984 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Unicast.Monitoring.CausationMutator
NServiceBus.Unicast.UnicastBus: 15:52:13,228 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Sagas.OriginatingSagaHeaderMutator
NServiceBus.Unicast.UnicastBus: 15:52:13,228 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Sagas.OriginatingSagaHeaderMutator
NServiceBus.Unicast.UnicastBus: 15:52:13,475 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Sagas.AutoCorrelateSagaOnReplyMutator
NServiceBus.Unicast.UnicastBus: 15:52:13,475 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Sagas.AutoCorrelateSagaOnReplyMutator
NServiceBus.Unicast.UnicastBus: 15:52:13,721 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.MessageHeaders.MessageHeaderManager
NServiceBus.Unicast.UnicastBus: 15:52:13,721 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.MessageHeaders.MessageHeaderManager
NServiceBus.Unicast.UnicastBus: 15:52:13,969 DEBUG UnicastBus:0 - Invoking transport message mutator: NServiceBus.Gateway.HeaderManagement.GatewayHeaderManager
NServiceBus.Unicast.UnicastBus: 15:52:13,969 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Invoking transport message mutator: NServiceBus.Gateway.HeaderManagement.GatewayHeaderManager

These are the log entries that occur shortly thereafter:

NServiceBus.Unicast.UnicastBus: 15:52:58,866 DEBUG UnicastBus:0 - Finished handling message.
NServiceBus.Unicast.UnicastBus: 15:52:58,866 [23] DEBUG NServiceBus.Unicast.UnicastBus [(null)] <(null)> - Finished handling message.
NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver: 15:53:00,900 DEBUG TimeoutPersisterReceiver:0 - Polling for timeouts at 09/20/2013 15:53:00.
NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver: 15:53:00,900 [17] DEBUG NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver [(null)] <(null)> - Polling for timeouts at 09/20/2013 15:53:00.
NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver: 15:53:01,152 DEBUG TimeoutPersisterReceiver:0 - Polling next retrieval is at 09/20/2013 15:54:01.
NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver: 15:53:01,152 [17] DEBUG NServiceBus.Timeout.Hosting.Windows.TimeoutPersisterReceiver [(null)] <(null)> - Polling next retrieval is at 09/20/2013 15:54:01.

Please help. I am at my wits end. I ported from MassTransit to NServiceBus specifically because of the separation between Commands, Events, and Messages, but after 4 days of banging my head against this, MassTransit looking mighty good.

I'm sure it's something really stupid I'm doing, but I'm a noob to NServicebus. I even bought the book to try and help me, to no avail. I cannot see what I'm doing wrong, and I have tried so many permutations of settings I cannot keep track of them all.

Updated 2013/09/23

A suggested I have:

Split the handler in two: a PortfolioCreatedHandler and a CreatePortfolioHandler.
Removed sealed from the handler
Created my own SubscriptionStorage, wrapping InMemorySubscriptionStorage for debugging purposes

I was already using IEvent to mark my events, and ICommand for my commands. Commands are published by the web controllers, and only the handlers publish events.

My TestSubscriptionStorage class is being called for Init and GetSubscriberAddressesForMessage, and not for Subscribe and Ubsubscribe, so it looks like the problem is that the events are not being subscribed, which is difficult to reconcile with the logs entries below.

Here are the logs mentioning the PortfolioCreatedEvent:

NServiceBus.Unicast.Routing.StaticMessageRouter: 09:34:25,886 DEBUG StaticMessageRouter:0 - Routing for message: Project.Domain.PM.Events.PortfolioCreatedEvent set to messagebus@SL-T50009909L
NServiceBus.Unicast.Routing.StaticMessageRouter: 09:34:25,886 [1] DEBUG NServiceBus.Unicast.Routing.StaticMessageRouter [(null)] <(null)> - Routing for message: Project.Domain.PM.Events.PortfolioCreatedEvent set to messagebus@SL-T50009909L
MessageType: Project.Domain.PM.Events.PortfolioCreatedEvent, Recoverable: True, TimeToBeReceived: Not set
MessageType: Project.Domain.PM.Events.PortfolioCreatedEvent, Recoverable: True, TimeToBeReceived: Not set
NServiceBus.Unicast.MessageHandlerRegistry: 09:34:25,906 DEBUG MessageHandlerRegistry:0 - Associated 'Project.Domain.PM.Events.PortfolioCreatedEvent' message with 'Project.PM.Handers.PortfolioCreatedHandler' handler
NServiceBus.Unicast.MessageHandlerRegistry: 09:34:25,906 [1] DEBUG NServiceBus.Unicast.MessageHandlerRegistry [(null)] <(null)> - Associated 'Project.Domain.PM.Events.PortfolioCreatedEvent' message with 'Project.PM.Handers.PortfolioCreatedHandler' handler
NServiceBus.Unicast.MessageHandlerRegistry: 09:34:25,916 DEBUG MessageHandlerRegistry:0 - Associated 'Project.Domain.PM.Commands.CreatePortfolioCommand' message with 'Project.PM.Handers.CreatePortfolioHandler' handler
NServiceBus.Unicast.MessageHandlerRegistry: 09:34:25,916 [1] DEBUG NServiceBus.Unicast.MessageHandlerRegistry [(null)] <(null)> - Associated 'Project.Domain.PM.Commands.CreatePortfolioCommand' message with 'Project.PM.Handers.CreatePortfolioHandler' handler
NServiceBus.Serializers.XML.XmlMessageSerializer: 09:34:26,120 DEBUG XmlMessageSerializer:0 - Initializing type: Project.Domain.PM.Events.PortfolioCreatedEvent, Project.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null
NServiceBus.Serializers.XML.XmlMessageSerializer: 09:34:26,120 [1] DEBUG NServiceBus.Serializers.XML.XmlMessageSerializer [(null)] <(null)> - Initializing type: Project.Domain.PM.Events.PortfolioCreatedEvent, Project.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null
NServiceBus.Unicast.Subscriptions.MessageDrivenSubscriptions.MessageDrivenSubscriptionManager: 09:34:35,445 INFO  MessageDrivenSubscriptionManager:0 - Subscribing to Project.Domain.PM.Events.PortfolioCreatedEvent, Project.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null at publisher queue messagebus@SL-T50009909L
NServiceBus.Unicast.Subscriptions.MessageDrivenSubscriptions.MessageDrivenSubscriptionManager: 09:34:35,445 [18] INFO  NServiceBus.Unicast.Subscriptions.MessageDrivenSubscriptions.MessageDrivenSubscriptionManager [(null)] <(null)> - Subscribing to Project.Domain.PM.Events.PortfolioCreatedEvent, Project.Domain, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null at publisher queue messagebus@SL-T50009909L
NServiceBus.AutomaticSubscriptions.DefaultAutoSubscriptionStrategy: 09:34:35,555 DEBUG DefaultAutoSubscriptionStrategy:0 - Autosubscribed to event Project.Domain.PM.Events.PortfolioCreatedEvent
NServiceBus.AutomaticSubscriptions.DefaultAutoSubscriptionStrategy: 09:34:35,555 [18] DEBUG NServiceBus.AutomaticSubscriptions.DefaultAutoSubscriptionStrategy [(null)] <(null)> - Autosubscribed to event Project.Domain.PM.Events.PortfolioCreatedEvent

If you do Bus.Send... does it then work? Following on from that do you really mean Publish or are you Sending? — Belogix
Bus.Send works 100%. Bus.Publish does absolutely nothing. From what I understand Bus.Send should be used for Commands, and Bus.Publish should be used for Events. — Sean Hederman
At this point in time I have given up on NServiceBus. It just plain does not work at all. I have pulled the code from the NServiceBus Step by Step guide, and even that simple scenario doesn't work. — Sean Hederman

David Boike David Boike · Accepted Answer · 2013-09-20T15:03:32

Well, thanks for buying the book! Yes, you can absolutely subscribe to events from the same AppDomain. Here are some thoughts as to what might be happening.

Do you see log entries that indicate they are subscribing to the event? If not then they are not subscribing.
You didn't post code for your command and event, so I'm not sure if you're using Unobtrusive Mode or directly implementing IEvent. NServiceBus 4 will not automatically subscribe to anything not recognized as an event.
I see InMemorySubscriptionStorage in your code. This makes it a little difficult to actually look at that storage. You could try injecting an ISubscriptionStorage somewhere so that you can look at what's in there in the debugger. Or just switch to the default Raven subscription storage for awhile so that you can navigate to the RavenDB Studio at http://localhost:8080 and look at the subscription documents.
I'm not sure why you sealed your handler class. I can't think of a specific problem that might cause but it might be a good idea to take it out to eliminate it as a possible problem.
Try separating your handlers into separate classes. There's no reason for one class to implement both anyway - the container will spin up new instances for each message so you can't share state, so it's probably best to not give another developer the impression that they could.
Also this issue could have something to do with it?

And of course I get to be a broken record sometimes with this but I would caution you not to publish events from a web application in the first place.