NServiceBus long running process that timesout

Question

We have noticed an issue with message handlers that have a long running request, if the request does not finish processing before the distributed transaction times out the same message is reprocessed on a new thread before the original message is done processing or before the original message even throws an error. The message does eventually get to the error queue.

Here is how we reproduced the issue:

Updated local machine config to a default timeout of 1 minute for transactions:

<system.transactions>        
   <defaultSettings distributedTransactionManagerName="" timeout="00:01:00" />       
    <machineSettings maxTimeout="00:01:00" />
</system.transactions>

Configured NSB message service to be multi threaded:

<MsmqTransportConfig NumberOfWorkerThreads="2" MaxRetries="2" />

Then in our handler did a thread sleep for 2 minutes (code below), what happens is that a message comes in on worker tread A. Once the 1 minute timeout occurs the same message gets handled on worker thread B and worker thread A is still sleeping. Worker thread A eventually comes back and errors with “Cannot enlist in transaction.” and then restarts processing the message again and this continues on both worker threads till the message eventually gets into the error queue.

public void Handle(RequestDataMessage message)
    {
        Logger.Info("==========================================================================");
        Logger.InfoFormat("Received request {0}.", message.DataId);
        Logger.InfoFormat("String received: {0}.", message.String);
        Logger.InfoFormat("Header 'Test' = {0}.", message.GetHeader("Test"));
        Logger.InfoFormat(Thread.CurrentPrincipal != null ? Thread.CurrentPrincipal.Identity.Name : string.Empty);

        var response = Bus.CreateInstance<DataResponseMessage>(m => 
        { 
            m.DataId = message.DataId;
            m.String = message.String;
        });

        response.CopyHeaderFromRequest("Test");
        response.SetHeader("1", "1");
        response.SetHeader("2", "2");

        Thread.Sleep(new TimeSpan(0, 2, 0));



        Logger.Info("========== Thread continued ===========");
        Logger.InfoFormat("Received request {0}.", message.DataId);
        Logger.InfoFormat("String received: {0}.", message.String);
        Logger.InfoFormat("Header 'Test' = {0}.", message.GetHeader("Test"));
        Logger.InfoFormat(Thread.CurrentPrincipal != null ? Thread.CurrentPrincipal.Identity.Name : string.Empty);

        Bus.Reply(response); //Try experimenting with sending multiple responses
    }

Is this a know issue, or is there a way we should design our code to avoid this type of intensive reprocessing that occurs?

Answer 1

Holding transactions out for that long in general is not a good idea. This means that all the resources that are participating in that transaction are locked. You should try to split the work that is going on in the handler. What type of work is the handler processing? Is it possible to split that work?

Regarding the other thread issue: where while thread A is sleeping, thread B is processing the same message, I am not seeing that behavior either in version 3.3.8 or version 4.0.2

Here's my handler:

    public void Handle(ProcessSomething message)
    {
        Console.WriteLine("{0} -- Thread {1} Handling MessageId {2}", DateTime.Now, Thread.CurrentThread.ManagedThreadId, Bus.CurrentMessageContext.Id);

        var response = Bus.CreateInstance<DataResponseMessage>(m =>
        {
            m.DataId = message.DataId;
            m.String = message.String;
        });

        Thread.Sleep(new TimeSpan(0, 1, 10));
        Console.WriteLine("{0} -- Thread {1} contiuned after sleep MessageId {2}", DateTime.Now, Thread.CurrentThread.ManagedThreadId, Bus.CurrentMessageContext.Id);

        Bus.Reply(response); //Try experimenting with sending multiple responses
    }

I put 4 messages on the queue, set the number of threads / MaxConcurrency to 2 and set the machine.config maxtimeout to 1 min and set the handler to sleep for 1 min 10 secs.

Bus.Reply will fail to enlist in the transaction. Because of the transaction timeout. This causes an exception and the message is retried. All messages that are being sent within the same handler are part of the same transaction. Hence this message fails and is retried. What I see is that thread 'A' handles Msmq message Id 'm1' sleeps continues with the same message 'm1' and throws when it tries to reply. I don't see thread 'B' picking up 'm1' while thread 'A' is sleeping.

Cheers.

Answer 2

Had a similar problem with transactions timing out but didn't want to change the default timeout for every transaction so ended up just changing the Transaction config for NServiceBus.

Configure.Transactions.Advanced(x => x.DefaultTimeout(TimeSpan.FromMinutes(3)));

This how ever is not ideal and would suggest breaking it down to more modular pieces of work.