NServiceBus unable to find handler

cgingles · February 8, 2018, 8:42pm

I have recently upgraded an application from NServiceBus 5 to 6, and for the most part it appears to be working. But I have found some errors in the log suggesting it can’t deliver a message, despite the handler being readily available.

public class AssociationPostingSagaData : ContainSagaData
{
    public string SagaKey { get; set; }

    [DocumentVersion]
    public int Version { get; set; }

    public string ParentSagaKey { get; set; }

    public Guid PostingId { get; set; }

    public JobData JobData { get; set; }

    public AssociationData AssociationData { get; set; }

    public HashSet<long> MissingRateCompanies { get; set; }
}

public class AssociationPostingSaga : Saga<AssociationPostingSagaData>,
    IAmStartedByMessages<PostAssociationCommand>,
    IAmStartedByMessages<PostAssociationCompanyBillCommand>,    // This is the command in question
    IHandleTimeouts<PostAssociationCompanyTimeout>
{
    // ... Autofac DI objects here

    [System.Diagnostics.CodeAnalysis.ExcludeFromCodeCoverage]
    protected override void ConfigureHowToFindSaga(SagaPropertyMapper<AssociationPostingSagaData> mapper)
    {
        mapper.ConfigureMapping<PostAssociationCommand>(message => message.SagaKey).ToSaga(saga => saga.SagaKey);
        mapper.ConfigureMapping<PostAssociationCompanyBillCommand>(message => message.SagaKey).ToSaga(saga => saga.SagaKey);
    }

    public async Task Handle(PostAssociationCompanyBillCommand message, IMessageHandlerContext context)
    {
        // ...
        await Task.CompletedTask;
    }

    // ... other handlers
}

The PostAssociationCompanyBillCommand handler is available within the saga and mapped. However, the logs show that NServiceBus can’t find it:

System.InvalidOperationException: No handlers could be found for message type: PostAssociationCompanyBillCommand
   at NServiceBus.LoadHandlersConnector.<Invoke>d__1.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\Incoming\LoadHandlersConnector.cs:line 31
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.DeserializeLogicalMessagesConnector.<Invoke>d__1.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\Incoming\DeserializeLogicalMessagesConnector.cs:line 33
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.SubscriptionReceiverBehavior.<Invoke>d__1.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Routing\MessageDrivenSubscriptions\SubscriptionReceiverBehavior.cs:line 29
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.ReceivePerformanceDiagnosticsBehavior.<Invoke>d__2.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Performance\Statistics\ReceivePerformanceDiagnosticsBehavior.cs:line 40
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.ProcessingStatisticsBehavior.<Invoke>d__0.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Performance\Statistics\ProcessingStatisticsBehavior.cs:line 27
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.TransportReceiveToPhysicalMessageProcessingConnector.<Invoke>d__1.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\Incoming\TransportReceiveToPhysicalMessageProcessingConnector.cs:line 39
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.MainPipelineExecutor.<Invoke>d__1.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\MainPipelineExecutor.cs:line 34
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.ReceiveStrategy.<TryProcessMessage>d__7.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Transports\Msmq\ReceiveStrategy.cs:line 111
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at NServiceBus.TransactionScopeStrategy.<ProcessMessage>d__2.MoveNext() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Transports\Msmq\TransactionScopeStrategy.cs:line 86

What would cause this? Am I missing something?

andreasohlund · February 12, 2018, 8:36am

The saga looks good to me, could it be that you have some assembly scanning issues that is causing the saga to not actually be loaded? (anything in the logs?)

andreasohlund · February 22, 2018, 7:25am

@cgingles did you manage to figure this out?

cgingles · February 22, 2018, 1:25pm

Andreas,

Thank you, yes I eventually did. Turns out the PostAssociationCompanyBillCommand command was being called from a different process, hence why it couldn’t be found.

Apparently NServiceBus 5 allows a saga to map commands in another process, and NServiceBus 6 does not. I had moved the handler into the same file as the saga, to satisfy the mapping, but this caused the above problem. The final solution was to move it back, and just delete the mapping from the saga.

Caleb

andreasohlund · February 22, 2018, 1:53pm

Not following, the mapping happens at development time, ie there is no knowledge of how things will be deployed at runtime. Can you elaborate?

command was being called from a different process, hence why it couldn’t be found

Are you saying that the command was handled by a different process(endpoint) processing messages from the same input queue as the process that was running your saga?

cgingles · February 22, 2018, 2:21pm

It is certainly confusing. I didn’t design the system, I’m just trying to upgrade it.

But yes, the command is handled by a different process endpoint than the one containing the saga.

The application contains three separate endpoints (Billing, BillGen, and Posting), each running in their own Host process. A task kicks off a process in Billing, which then fires a PostAssociationCommand command to Posting, where the saga lives. The saga originally contained a mapping for two command handlers, PostAssociationCommand and PostAssociationCompanyBillCommand:

mapper.ConfigureMapping<PostAssociationCommand>(message => message.SagaKey).ToSaga(saga => saga.SagaKey);
mapper.ConfigureMapping<PostAssociationCompanyBillCommand>(message => message.SagaKey).ToSaga(saga => saga.SagaKey);

The PostAssociationCommand handler runs, which in turn fires off several hundred PostAssociationCompanyBillCommand commands. Now, despite the saga having a mapping to PostAssociationCompanyBillCommand, it’s handler is actually in Billing, not Posting.

In NServiceBus 5, this worked fine. Messages were fired between hosts as expected, and the command mapping in the saga was fine. In NServiceBus 6, this no longer works, the Posting process (containing the saga) crashes with an error:

System.Exception: Saga AssociationPostingSaga contains a mapping for PostAssociationCompanyBillCommand in the ConfigureHowToFindSaga method, but does not handle that message. If AssociationPostingSaga is supposed to handle this message, it should implement IAmStartedByMessages<PostAssociationCompanyBillCommand> or IHandleMessages<

andreasohlund · February 22, 2018, 2:52pm

Ok now I get it. The saga check was added in v6 and would prevent your endpoint to start like you describe. In v5 the endpoint would start but throw an error like described here when trying to process a message:

One final question, why would you have a saga mapping for PostAssociationCompanyBillCommand if the saga doesn’t the message?

cgingles · February 22, 2018, 3:10pm

To be honest, I don’t know, the dev who originally wrote that saga isn’t here anymore. I’m guessing it was just a misunderstanding, the assumption that a saga oversees a series of commands that were being run, and that the saga would have to map all of them in order for it to work (i.e. how would the saga keep track of commands being run if it doesn’t know about them). It isn’t obvious that this isn’t required, which is why it took me so long to delete that bad mapping.

andreasohlund · February 23, 2018, 7:53am

The current exception message is

$"Saga {sagaType.Name} contains a mapping for {msgType} in the ConfigureHowToFindSaga method, but does not handle that message. If {sagaType.Name} is supposed to handle this message, it should implement IAmStartedByMessages<{msgType}> or IHandleMessages<{msgType}>."

github.com

Particular/NServiceBus/blob/master/src/NServiceBus.Core/Sagas/SagaMetadata.cs#L214


      
          
          
        finders.Add(mapping.CreateSagaFinderDefinition(sagaEntityType));
              }
          
          
    foreach (var messageType in associatedMessages)
              {
                  if (messageType.IsAllowedToStartSaga)
                  {
                      var match = mapper.Mappings.FirstOrDefault(m => m.MessageType.IsAssignableFrom(messageType.MessageType));
                      if (match == null)
                      {
                          var simpleName = messageType.MessageType.Name;
                          throw new Exception($"Message type {simpleName} can start the saga {sagaType.Name} (the saga implements IAmStartedByMessages<{simpleName}>) but does not map that message to saga data. In the ConfigureHowToFindSaga method, add a mapping using:{Environment.NewLine}    mapper.ConfigureMapping<{simpleName}>(message => message.SomeMessageProperty).ToSaga(saga => saga.MatchingSagaProperty);");
                      }
                  }
              }
          
          
    return new SagaMetadata(sagaType.FullName, sagaType, sagaEntityType.FullName, sagaEntityType, correlationProperty, associatedMessages, finders);
          }
          
          
static void ApplyScannedFinders(SagaMapper mapper, Type sagaEntityType, IEnumerable<Type> availableTypes, Conventions conventions)

Perhaps we can tweak to to say “… or remove the mapping if the saga isn’t handling the message”.

@cgingles do you think that would have helped you to resolve this?

Thanks for taking the time to help us improve