NSB7 Multiple sagas handle the same message

, ,
1

Hi,

I have two SqlSagas that sends a message to the same handler and then waits for a reply from that handler. But using the same message from both sagas seems to confuse NSB when it gets the reply from the handler becuase it throws an exception

2018-06-19 10:35:09 [Information] [NServiceBus.Serilog.MessageReceived] Receive message Modules.Messages.ActiveModulesForAccount "b113fbf4-580a-4e10-bdfe-a904008d7e46". 2018-06-19 10:35:09 [Information] [NServiceBus.RecoverabilityExecutor] Immediate Retry is going to retry message 'b113fbf4-580a-4e10-bdfe-a904008d7e46' because of an exception: System.Collections.Generic.KeyNotFoundException: No item found in behavior context with key: NServiceBus.Sagas.ActiveSagaInstance at NServiceBus.Extensibility.ContextBag.Get[T](String key) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Extensibility\ContextBag.cs:line 71 at CaptureSagaStateBehavior.Invoke(IInvokeHandlerContext context, Func1 next)
at NServiceBus.LoadHandlersConnector.Invoke(IIncomingLogicalMessageContext context, Func2 stage) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Pipeline\Incoming\LoadHandlersConnector.cs:line 42 at NServiceBus.InvokeSagaNotFoundBehavior.Invoke(IIncomingLogicalMessageContext context, Func2 next) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Sagas\InvokeSagaNotFoundBehavior.cs:line 18
at NServiceBus.DeserializeLogicalMessagesConnector.Invoke(IIncomingPhysicalMessageContext context, Func2 stage) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Pipeline\Incoming\DeserializeLogicalMessagesConnector.cs:line 33 at NServiceBus.SubscriptionReceiverBehavior.Invoke(IIncomingPhysicalMessageContext context, Func2 next) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Routing\MessageDrivenSubscriptions\SubscriptionReceiverBehavior.cs:line 29
at NServiceBus.ProcessingStatisticsBehavior.Invoke(IIncomingPhysicalMessageContext context, Func2 next) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Performance\Statistics\ProcessingStatisticsBehavior.cs:line 25 at Infrastructure.NServiceBus.ExtractSqlConnectionBehavior.Invoke(IIncomingPhysicalMessageContext context, Func1 next) in C:\dev\astral\src\Astral\Infrastructure\NServiceBus\ExtractSqlConnectionBehavior.cs:line 37
at NServiceBus.TransportReceiveToPhysicalMessageProcessingConnector.Invoke(ITransportReceiveContext context, Func2 next) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Pipeline\Incoming\TransportReceiveToPhysicalMessageProcessingConnector.cs:line 39 at NServiceBus.MainPipelineExecutor.Invoke(MessageContext messageContext) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Pipeline\MainPipelineExecutor.cs:line 34 at NServiceBus.Transport.SQLServer.DelayedDeliveryMessagePump.<>c__DisplayClass1_0.<<Init>b__0>d.MoveNext() in C:\BuildAgent\work\1c57be3e94b4bd73\src\NServiceBus.SqlServer\DelayedDelivery\DelayedDeliveryMessagePump.cs:line 23 --- End of stack trace from previous location where exception was thrown --- at NServiceBus.Transport.SQLServer.ReceiveStrategy.TryProcessingMessage(Message message, TransportTransaction transportTransaction) in C:\BuildAgent\work\1c57be3e94b4bd73\src\NServiceBus.SqlServer\Receiving\ReceiveStrategy.cs:line 63 at NServiceBus.Transport.SQLServer.ProcessWithNativeTransaction.TryProcess(Message message, TransportTransaction transportTransaction) in C:\BuildAgent\work\1c57be3e94b4bd73\src\NServiceBus.SqlServer\Receiving\ProcessWithNativeTransaction.cs:line 92

If I create two different messages/handlers then everything works. Is this by design or is it a bug? I thought that NSB should be able to resolve the correct saga from the headers.

Regars,
Tommy

2

Hi @Tommy

Just to verify: Have you made sure that all messages used (especially the response type) have been marked with the IMessage or ICommand marker interfaces (or declared via conventions)?

3

Hi @Tim

Yes, both messages are marked with IMessage.

4

Thanks for checking @Tommy. What transport and persistence are you using (and what versions)? Do you have a project you can share with us to reproduce your issue?

5

I’m using SqlServerTransport and SqlPersistence. I’ll try to make small project to reproduce the issue.

6

I created a gist https://gist.github.com/Rensvind/c33b4a9314c6a4bb90f49a19993e3ee0

While creating the project I noticed that the problem only appears when using Serilog. If you remove everything serilog-related the code works as expected.

7

Thanks for the repro @Tommy. Your observation is correct as this exception seems to originate from the NServiceBus.Serilog package as also hinted by the stacktrace:

Immediate Retry is going to retry message ‘b113fbf4-580a-4e10-bdfe-a904008d7e46’ because of an exception: System.Collections.Generic.KeyNotFoundException: No item found in behavior context with key: NServiceBus.Sagas.ActiveSagaInstance at NServiceBus.Extensibility.ContextBag.Get[T](String key) in C:\BuildAgent\work\b549d46003942065\src\NServiceBus.Core\Extensibility\ContextBag.cs:line 71 at CaptureSagaStateBehavior.Invoke

The CaptureSagaStateBehavior is part of the Serilog package and at first glance it looks like the behavior didn’t take into account the possibility of a message having handlers in mutliple sagas where only one saga will actually handle the message as it’s a response message.

I’ll look a bit closer into the Serilog behavior to verify this assumption. Please note that the Serilog package is a community package and not supported by Particular Software.

8

Hey @Tommy
I have verified that this issue is indeed due to a bug in the NServiceBus Serilog package. I’ve raised an issue in the github repo: CaptureSagaStateBehavior throws when handling reply type handled by multiple sagas · Issue #16 · NServiceBusExtensions/NServiceBus.Serilog · GitHub. I’d recommend to watch that issue to receive updates on this matter.

9

Hi @Tim
Thank you so much for the help! I’ll be watching the issue.

10

@Tommy tims fix is now deployed. it may take nuget up to an hour to re-index

2 Likes