Outbox, Exception (Sql Server, NHibernate, RabbitMQ)

1

Hi Everyone,
I m using NServiceBus, Sql Server, NHibernate, Outbox, with RabbitMQ Transport
getting the following exception:
(component versions: NServiceBus 5.2.25, NServiceBus.NHibernate 6.2.7, NServiceBus.RabbitMQ 3.5.2, NHibernate 4.0.1.4000)
NHibernate.Exceptions.GenericADOException: could not insert: [NServiceBus.Outbox.NHibernate.OutboxRecord][SQL: INSERT INTO OutboxRecord (MessageId, Dispatched, DispatchedAt, TransportOperations) VALUES (?, ?, ?, ?); select SCOPE_IDENTITY()] —> System.Data.SqlClient.SqlException: Violation of PRIMARY KEY constraint ‘PK__OutboxRe__C87C0C9C9882B77A’. Cannot insert duplicate key in object ‘dbo.OutboxRecord’. The duplicate key value is (Oneview.RoomReadyService/3ea488f5-cd9c-450e-8ccf-a8f00096cb75).
The statement has been terminated.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData() at System.Data.SqlClient.SqlDataReader.get_MetaData() at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry)
at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method)
at NHibernate.AdoNet.AbstractBatcher.ExecuteReader(IDbCommand cmd)
at NHibernate.Id.IdentityGenerator.InsertSelectDelegate.ExecuteAndExtract(IDbCommand insert, ISessionImplementor session)
at NHibernate.Id.Insert.AbstractReturningDelegate.PerformInsert(SqlCommandInfo insertSQL, ISessionImplementor session, IBinder binder)
— End of inner exception stack trace —
at NHibernate.Id.Insert.AbstractReturningDelegate.PerformInsert(SqlCommandInfo insertSQL, ISessionImplementor session, IBinder binder)
at NHibernate.Persister.Entity.AbstractEntityPersister.Insert(Object[] fields, Object obj, ISessionImplementor session)
at NHibernate.Action.EntityIdentityInsertAction.Execute()
at NHibernate.Engine.ActionQueue.Execute(IExecutable executable)
at NHibernate.Event.Default.AbstractSaveEventListener.PerformSaveOrReplicate(Object entity, EntityKey key, IEntityPersister persister, Boolean useIdentityColumn, Object anything, IEventSource source, Boolean requiresImmediateIdAccess)
at NHibernate.Event.Default.AbstractSaveEventListener.SaveWithGeneratedId(Object entity, String entityName, Object anything, IEventSource source, Boolean requiresImmediateIdAccess)
at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.SaveWithGeneratedOrRequestedId(SaveOrUpdateEvent event)
at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.EntityIsTransient(SaveOrUpdateEvent event)
at NHibernate.Event.Default.DefaultSaveOrUpdateEventListener.OnSaveOrUpdate(SaveOrUpdateEvent event)
at NHibernate.Impl.SessionImpl.FireSave(SaveOrUpdateEvent event)
at NHibernate.Impl.SessionImpl.Save(Object obj)
at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107 at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95
at NServiceBus.Persistence.NHibernate.OpenSessionBehavior.InnerInvoke(BehaviorContext context, Action next, Func1 connectionRetriever) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\SharedSession\OpenSessionBehavior.cs:line 83 at NServiceBus.Persistence.NHibernate.OpenSessionBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\SharedSession\OpenSessionBehavior.cs:line 58 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.UnitOfWorkBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\UnitOfWork\UnitOfWorkBehavior.cs:line 42 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.Transports.RabbitMQ.OpenPublishChannelBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\a9e6741f41af7061\src\NServiceBus.RabbitMQ\OpenPublishChannelBehavior.cs:line 19 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.OutboxDeduplicationBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Outbox\OutboxDeduplicationBehavior.cs:line 40 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.Persistence.NHibernate.OpenSqlConnectionBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\5135de308b2f3016\src\NServiceBus.NHibernate\SharedSession\OpenSqlConnectionBehavior.cs:line 32 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.ChildContainerBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Unicast\Behaviors\ChildContainerBehavior.cs:line 17 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.<>c__DisplayClass4_0.<InvokeNext>b__0() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 95 at NServiceBus.ProcessingStatisticsBehavior.Invoke(IncomingContext context, Action next) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Monitoring\ProcessingStatisticsBehavior.cs:line 23 at NServiceBus.BehaviorChain1.InvokeNext(T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 107
at NServiceBus.BehaviorChain1.Invoke() in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\BehaviorChain.cs:line 52 at NServiceBus.Pipeline.PipelineExecutor.Execute[T](BehaviorChain1 pipelineAction, T context) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Pipeline\PipelineExecutor.cs:line 129
at NServiceBus.Unicast.Transport.TransportReceiver.OnTransportMessageReceived(TransportMessage msg) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Unicast\Transport\TransportReceiver.cs:line 413
at NServiceBus.Unicast.Transport.TransportReceiver.ProcessMessage(TransportMessage message) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Unicast\Transport\TransportReceiver.cs:line 344
at NServiceBus.Unicast.Transport.TransportReceiver.TryProcess(TransportMessage message) in C:\BuildAgent\work\a93f853f0c1b9532\src\NServiceBus.Core\Unicast\Transport\TransportReceiver.cs:line 230
at NServiceBus.Transports.RabbitMQ.RabbitMqDequeueStrategy.ConsumeMessages(Object state) in C:\BuildAgent\work\a9e6741f41af7061\src\NServiceBus.RabbitMQ\RabbitMqDequeueStrategy.cs:line 199

Any ideas on how i can overcome that?
Thanks

2

That can happen if the same message is processed more-than-once. This makes sure that your handlers operate in an transactional exact-once behavior to guard consistency.

See the following documentation on how the outbox works:

In most cases you can ignore this but if this happens very very frequently then this might indicate other issues. You should then try to discover why the same message is being transmitted multiple times.

– Ramon

3

We are experiencing the same thing with v7.1.10. Reading the NServiceBus code, I’m a bit concerned. This exception happens at the outboxStorage.Store() line, that is, after the handler was invoked (at the next(physicalMessageContext) line). That is, when you see this exception, the handler has actually been invoked twice.

Isn’t this the guarantee of the outbox, that a message handler will only be invoked once?