Autorenew lock fails silently

[Timothy Frye]

I have a long running process using MassTransit and ASB.  We have 5 minute lock durations, and auto renew set to 4 minutes.  

We have logs from a processor on a machine saying it received a message at 4:08 and Renewed Lock for that message id at 4:12 and 4:16

We have a log saying processor 2 on a different machine received the message at 4:19

At 4:20 we get a WARN Lost Message Lock: {id} Microsoft.ServiceBus.Messaging.MessageLockLostException: The lock supplied is invalid. Either the lock expired, or the message has already been removed from the queue.

and from then forward starting at 4:23 and every 4 minutes from then on the new processor renews the lock with no issues.

Is there a known issue with locks silently failing to renew, or falsely reporting a successful renewal?

[Chris Patterson]

Which transport (.NET framework, or .NET Standard -- which package) and versions are you using, and what does your configuration code look like?

--
You received this message because you are subscribed to the Google Groups "masstransit-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to masstransit-dis...@googlegroups.com.
To post to this group, send email to masstrans...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/masstransit-discuss/9dda94e3-4737-40ad-b4a5-5091cc85fae7%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Timothy Frye]

We are using .NET framework, compiling under 4.6.1 with MassTransit 5.1.5.  Our config code uses

We use the following packages:

MassTransit

MassTransit.Autofac

MassTransit.AzureServiceBus

MassTransit.NLog

MassTransit.RabbitMQ 

We had configuration code determine which transport layer to use.  We are firmly using Azure Service Bus now.

We declare our bus with:  

var host = bus.Host(

    connectionString: Config.AzureServiceBusConnectionString,

    configure: config =>

    {

        var connectionString = new ServiceBusConnectionStringBuilder(Config.AzureServiceBusConnectionString);

        config.TokenProvider = TokenProvider.CreateSharedAccessSignatureTokenProvider(

            keyName: connectionString.SharedAccessKeyName,

            sharedAccessKey: connectionString.SharedAccessKey,

            tokenTimeToLive: TimeSpan.FromDays(1),

            tokenScope: TokenScope.Namespace);

    });

All of our endpoints have the default 5 minute lock duration and no duplicate detection.

Our send endpoint and receive endpoints use the same bus

The receive endpoints have identical configuration aside from queue name.

bus.ReceiveEndpoint(host, Config.QueueName, config =>

{

    config.EnableDeadLetteringOnMessageExpiration = false;

    config.UseRenewLock(TimeSpan.FromSeconds(240));

    config.MaxConcurrentCalls = 1;

    config.PrefetchCount = 1;

    config.Consumer<MyConsumer>(context);

});

Please let me know if I can supply and additional information

On Wednesday, January 30, 2019 at 12:00:01 PM UTC-5, Chris Patterson wrote:

Which transport (.NET framework, or .NET Standard -- which package) and versions are you using, and what does your configuration code look like?

On Wed, Jan 30, 2019 at 8:53 AM Timothy Frye <timoth...@gmail.com> wrote:

I have a long running process using MassTransit and ASB.  We have 5 minute lock durations, and auto renew set to 4 minutes.  

We have logs from a processor on a machine saying it received a message at 4:08 and Renewed Lock for that message id at 4:12 and 4:16

We have a log saying processor 2 on a different machine received the message at 4:19

At 4:20 we get a WARN Lost Message Lock: {id} Microsoft.ServiceBus.Messaging.MessageLockLostException: The lock supplied is invalid. Either the lock expired, or the message has already been removed from the queue.

and from then forward starting at 4:23 and every 4 minutes from then on the new processor renews the lock with no issues.

Is there a known issue with locks silently failing to renew, or falsely reporting a successful renewal?

--
You received this message because you are subscribed to the Google Groups "masstransit-discuss" group.

To unsubscribe from this group and stop receiving emails from it, send an email to masstransit-discuss+unsub...@googlegroups.com.

[Chris Patterson]

Well, UseRenewLock has been removed from 5.2.3, at least from the .NET core library, since it's automatically performed by the Azure client library. It might have been removed from the regular .NET framework version of the transport as well in favor of the client-supported behavior.

To unsubscribe from this group and stop receiving emails from it, send an email to masstransit-dis...@googlegroups.com.

To post to this group, send email to masstrans...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/masstransit-discuss/9dda94e3-4737-40ad-b4a5-5091cc85fae7%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

You received this message because you are subscribed to the Google Groups "masstransit-discuss" group.

To unsubscribe from this group and stop receiving emails from it, send an email to masstransit-dis...@googlegroups.com.

To post to this group, send email to masstrans...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/masstransit-discuss/9d881479-dbb2-4806-b5e1-a480173e3f9c%40googlegroups.com.

[Timothy Frye]

Thank you for taking the time to reply.  I will update the version, and we will monitor.

[Timothy Frye]

I don't want to move the goal posts, but I started this thread with one question, which has been answered, but the question came about as a specific case in a larger issue.  We seem to be seeing some messages delivered multiple times.  At first we assumed it was due to a failed renew causing the message to be delivered to another consumer, but we have seen logs indicating that a message we assume done is delivered after the lock time to another consumer.  

2019-01-25 18:15:55.2441 DEBUG SEND sb://{Endpoint} 0a1f0000-5d03-0015-1fb7-08d6831afd4c {FullMessageType}

2019-01-25 18:15:55.2910 DEBUG Receiving 499:0a1f00005d0300151fb708d6831afd4c({MessageType})

2019-01-25 18:15:57.8695 DEBUG RECEIVE sb://{Endpoint} 0a1f0000-5d03-0015-1fb7-08d6831afd4c {FullMessageType} {Consumer}(00:00:02.5772523)

2019-01-25 18:20:55.5082 DEBUG Receiving 1570:0a1f00005d0300151fb708d6831afd4c({MessageType})

2019-01-25 18:20:57.1801 DEBUG RECEIVE sb://{Endpoint} 0a1f0000-5d03-0015-1fb7-08d6831afd4c {FullMessageType} {Consumer}(00:00:01.6691382)

We are seeing no errors from the consumer in this case.  We see the redelivery occur 5 minutes after the first receiving, which is the lock duration.  Is it possible for the acknowledgement to silently fail?  We are working to improve idempotency to counter this, but were not expecting it.  

[Chris Patterson]

What you're seeing is the effect of having DeliveryCount > 1 and exceeding the lock timeout. You're probably blocking threads which prevents the RenewLock from executing in the TPL. I've seen this many times, sucks to figure out, but it isn't MassTransit causing it.

--

You received this message because you are subscribed to the Google Groups "masstransit-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to masstransit-dis...@googlegroups.com.
To post to this group, send email to masstrans...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/masstransit-discuss/f9230d6c-7a0d-4664-bcc0-e2ce71d4deef%40googlegroups.com.