Strange behavior with STOMP nack in client-individual subscriber

415 views
Skip to first unread message

lgaggini

unread,
Sep 25, 2014, 8:59:24 AM9/25/14
to rabbitm...@googlegroups.com
Hi All,

I'm experiencing a strange behavior with RabbitMQ 3.3.5 and STOMP client stomp.py (https://github.com/jasonrbriggs/stomp.py) with one consumer.

I subscribe by STOMP to a queue with ack mode 'client-individual' and I try to nack received messages to test the redelivery of the nacked message. It works correctly and the subscribe receive the same message again (message with body 'Test1') and the broker waiting for the ack for the message redelivered:


conn.send(body='Test1', destination='/queue/versamenti', headers={'persistent': True})
INFO:stomp.py:Sending frame ['SEND', '\n', 'destination:/queue/versamenti\n', 'persistent:True\n', '\n', 'Test1', '\x00']

conn.subscribe(destination='/queue/versamenti', id=1, ack='client-individual')
INFO:stomp.py:Sending frame ['SUBSCRIBE', '\n', 'ack:client-individual\n', 'destination:/queue/versamenti\n', 'id:1\n', '\n', '\x00']
INFO:stomp.py:Received frame: 'MESSAGE', headers={'message-id': 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1', 'content-length': '5', 'destination': '/queue/versamenti', 'subscription': '1'}, body='Test1'

conn.nack(id='T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1', subscription=1)
INFO:stomp.py:Sending frame ['NACK', '\n', 'message-id:T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1\n', 'subscription:1\n', '\n', '\x00']
INFO:stomp.py:Received frame: 'MESSAGE', headers={'message-id': 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@2', 'content-length': '5', 'destination': '/queue/versamenti', 'subscription': '1'}, body='Test1'

This is the behavior that I expect also if I miss the redelivered flag in the redelivered message.

At this point, if I send the same nack again (message-id: 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1'), I correctly don't have the redelivery of the message currently in unacked state (message-id: 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@2'), but this message on the broker queue goes from the unacked state to ready state without redelivery to the subscriber:

conn.nack(id='T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1', subscription=1)
INFO:stomp.py:Sending frame ['NACK', '\n', 'message-id:T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1\n', 'subscription:1\n', '\n', '\x00']

I feel I don't understand something.

Thank you for the support,

Best regards.

Michael Klishin

unread,
Sep 25, 2014, 9:03:48 AM9/25/14
to lgaggini, rabbitm...@googlegroups.com
On 25 September 2014 at 16:59:29, lgaggini (l...@libersoft.it) wrote:
> At this point, if I send the same nack again (message-id: 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1'),
> I correctly don't have the redelivery of the message currently
> in unacked state (message-id: 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@2'),
> but this message on the broker queue goes from the unacked state
> to ready state without redelivery to the subscriber:
>
> conn.nack(id='T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1',
> subscription=1)
> INFO:stomp.py:Sending frame ['NACK', '\n', 'message-id:T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1\n',
> 'subscription:1\n', '\n', '\x00']

1. Anything in the RabbitMQ log?
2. Can you please put together a script that we can run to reproduce? 
--
MK

Staff Software Engineer, Pivotal/RabbitMQ

lgaggini

unread,
Sep 25, 2014, 10:49:21 AM9/25/14
to rabbitm...@googlegroups.com, l...@libersoft.it

On Thursday, September 25, 2014 3:03:48 PM UTC+2, Michael Klishin wrote:
On 25 September 2014 at 16:59:29, lgaggini (l...@libersoft.it) wrote:
> At this point, if I send the same nack again (message-id: 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1'),  
> I correctly don't have the redelivery of the message currently  
> in unacked state (message-id: 'T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@2'),  
> but this message on the broker queue goes from the unacked state  
> to ready state without redelivery to the subscriber:
>  
> conn.nack(id='T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1',  
> subscription=1)
> INFO:stomp.py:Sending frame ['NACK', '\n', 'message-id:T_1@@session-SLLlG4GtwazK6-ySQlOtpA@@1\n',  
> 'subscription:1\n', '\n', '\x00']


Hi Michael,
 
1. Anything in the RabbitMQ log?

=ERROR REPORT==== 25-Sep-2014::14:41:55 ===
connection <0.5642.0>, channel 1 - soft error:
{amqp_error,precondition_failed,"unknown delivery tag 1",'basic.nack'}
 
2. Can you please put together a script that we can run to reproduce? 


I write a little script, stomp_nack.py to reproduce the problem (in attachment with an example output). 
You need to configure in the script rabbitmq server address and queue name and you need to install stomp.py python library, (pip install stomp.py).

Best regards. 
stomp_nack.py
stomp_nack.py.out

Michael Klishin

unread,
Sep 25, 2014, 3:46:14 PM9/25/14
to lgaggini, rabbitm...@googlegroups.com
On 25 September 2014 at 18:49:27, lgaggini (l...@libersoft.it) wrote:
> =ERROR REPORT==== 25-Sep-2014::14:41:55 ===
> connection <0.5642.0>, channel 1 - soft error:
> {amqp_error,precondition_failed,"unknown delivery tag
> 1",'basic.nack'}

OK, thanks, this is already something (but not necessarily an indication
of a bug).

> 2. Can you please put together a script that we can run to reproduce?
>
>
> I write a little script, stomp_nack.py to reproduce the problem
> (in attachment with an example output).

Thank you, we'll get to it as time permits.

lgaggini

unread,
Sep 26, 2014, 3:32:23 AM9/26/14
to rabbitm...@googlegroups.com, l...@libersoft.it
You're welcome and thank you for the support.
 
Best regards.
Reply all
Reply to author
Forward
0 new messages