[rabbitmq-discuss] Race condition when acknowledging messages?

[Roger Hu]

We are running RabbitMQ v3.3.1 and librabbitmq v1.5.2 and have noticed that 
our client is periodically getting these exceptions:

ChannelError: channel error 406, message: PRECONDITION_FAILED - unknown 
delivery tag 704117

We have a dedicated separate connection and channel setup to receive the 
message and ack it back immediately.     We notice that the delivery tag of 
the same as the one we're
trying to acknowledge back, so this tag ID appears to be consistent and one 
that RMQ should know about.  However, it appears to trigger a 
PRECONDITION_FAILED, making us think
we made a duplicate ACK acknowledgment somewhere.  We have placed logging 
statements to centralize all message acknowledgments and only see one ACK, 
confirming our belief
that it is a single ACK being made.

We noticed in this code 
(https://github.com/rabbitmq/rabbitmq-server/blob/master/src/rabbit_channel.erl#L741-750) 
that the record of the note being
sent is handled by the rabbit_writer process.

            ok = rabbit_writer:send_command(
                   WriterPid,
                   #'basic.get_ok'{delivery_tag  = DeliveryTag,
                                   redelivered   = Redelivered,
                                   exchange      = ExchangeName#resource.name,
                                   routing_key   = RoutingKey,
                                   message_count = MessageCount},
                   Content),
            State1 = monitor_delivering_queue(NoAck, QPid, QName, State),
            {noreply, record_sent(none, not(NoAck), Msg, State1)};


 However, the delivery tag information appears to get record later 
in https://github.com/rabbitmq/rabbitmq-server/blob/master/src/rabbit_channel.erl#L1380-1384:

   true  -> queue:in({DeliveryTag, ConsumerTag, {QPid, MsgId}},
                                  UAMQ);


Our current workaround is to delay acknowledging the message instead of 
trying to ack it right away.  The problem shows up intermittently, possibly 
when there are large queue volumes on the RMQ box and possibly when we 
start to queue up 50-60K unacknowledged messages, which may cause issues 
for the delivery tag to be added to the unacked list (UAMQ).

Is it possible there is a race condition in which the delivery tag received 
by the client has yet to be recorded?    Again, the problem happens 
intermittently but would like to suggest changing the code to record the 
delivery tag (in record_sent() before dispatching rabbit_writer.  

Would appreciate any thoughts about changing the code to add the message 
before responding back to the writer.

Thanks,

Roger
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20140616/e2a373e9/attachment.html>