[rabbitmq-discuss] Delay delivering messages

Tue Sep 21 13:13:57 BST 2010

Hi,

I've ran tcpdump on the consumer machine when the problem is occurring. The
Java process running the consumer has definitely gone. list_connections on
the broker shows there is still a connection:

The output of tcpdump:

11:55:15.277607 IP 192.168.2.64.59061 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
1777345129:1777345331, ack 955208465, win 33304, options [nop,nop,TS val
609354052 ecr 6381321], length 202
11:55:30.103223 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
3156241994:3156242015, ack 938385998, win 33304, options [nop,nop,TS val
609354200 ecr 6382341], length 21
11:56:19.384882 IP 192.168.2.64.59061 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:202, ack 1, win 33304, options [nop,nop,TS val 609354692 ecr 6381321],
length 202
11:56:34.208833 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:21, ack 1, win 33304, options [nop,nop,TS val 609354840 ecr 6382341],
length 21
11:57:23.489908 IP 192.168.2.64.59061 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:202, ack 1, win 33304, options [nop,nop,TS val 609355332 ecr 6381321],
length 202
11:57:38.313950 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:21, ack 1, win 33304, options [nop,nop,TS val 609355480 ecr 6382341],
length 21
11:58:27.594809 IP 192.168.2.64.59061 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:202, ack 1, win 33304, options [nop,nop,TS val 609355972 ecr 6381321],
length 202
11:58:42.417220 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:21, ack 1, win 33304, options [nop,nop,TS val 609356120 ecr 6382341],
length 21
11:59:31.693171 IP 192.168.2.64.59061 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:202, ack 1, win 33304, options [nop,nop,TS val 609356612 ecr 6381321],
length 202
11:59:46.516762 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:21, ack 1, win 33304, options [nop,nop,TS val 609356760 ecr 6382341],
length 21
12:00:35.791504 IP 192.168.2.64.59061 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [R.], seq 203,
ack 1, win 33304, length 0
12:00:50.614290 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [FP.], seq
0:21, ack 1, win 33304, options [nop,nop,TS val 609357400 ecr 6382341],
length 21
12:01:54.714736 IP 192.168.2.64.59048 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [R.], seq 22,
ack 1, win 33304, length 0
12:20:38.475816 IP 192.168.2.56.51686 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
1037575082:1037575118, ack 26733943, win 65535, options [nop,nop,TS val
115719776 ecr 11565352], length 36
12:20:38.475824 IP 192.168.2.56.51686 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
36:252, ack 1, win 65535, options [nop,nop,TS val 115719776 ecr 11565352],
length 216
12:20:38.476098 IP 192.168.2.56.51686 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
252:288, ack 1, win 65535, options [nop,nop,TS val 115719776 ecr 11565352],
length 36
12:20:38.476112 IP 192.168.2.56.51686 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
288:543, ack 1, win 65535, options [nop,nop,TS val 115719776 ecr 11565352],
length 255
12:20:38.494336 IP 192.168.2.56.51683 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [.], ack
14626648, win 65535, options [nop,nop,TS val 115719776 ecr 14886791], length
0
12:20:38.494473 IP 192.168.2.56.51683 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [.], ack 332,
win 65535, options [nop,nop,TS val 115719776 ecr 14886791], length 0
12:20:38.597240 IP 192.168.2.56.51683 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
0:21, ack 332, win 65535, options [nop,nop,TS val 115719777 ecr 14886791],
length 21
12:20:38.665082 IP 192.168.2.56.51683 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
21:42, ack 332, win 65535, options [nop,nop,TS val 115719777 ecr 14886911],
length 21
12:22:11.371665 IP 192.168.2.56.51686 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
543:579, ack 1, win 65535, options [nop,nop,TS val 115720704 ecr 14886791],
length 36
12:22:11.371673 IP 192.168.2.56.51686 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
579:834, ack 1, win 65535, options [nop,nop,TS val 115720704 ecr 14886791],
length 255
12:22:11.388416 IP 192.168.2.56.51683 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [.], ack 663,
win 65535, options [nop,nop,TS val 115720704 ecr 14979686], length 0
12:22:11.486539 IP 192.168.2.56.51683 >
ec2-79-125-24-245.eu-west-1.compute.amazonaws.com.amqp: Flags [P.], seq
42:63, ack 663, win 65535, options [nop,nop,TS val 115720705 ecr 14979686],
length 21

The consumer was shutdown at approx 11.50. More than an hour later I am
still seeing the connection on the broker.

Thanks,
Michael

On Sat, Sep 18, 2010 at 11:34 PM, Matthew Sackman <matthew at rabbitmq.com>wrote:

> On Thu, Sep 16, 2010 at 09:01:17AM +0100, Michael Burns wrote:
> > I've noticed sometimes that there are extra connections hanging about on
> the
> > RabbitMQ broker (using rabbitmqctl  list_connections).
> > It's possible sometimes in our consumers that we are not always closing
> the
> > connection cleanly (sometimes people are simply killing their app rather
> > than shutting down cleanly).
> >
> > Could this somehow explain why we experience these delays?
>
> Yes. If the TCP socket is still alive then Rabbit will not believe the
> connection has died, and so will not make unacknowledged messages
> available to other consumers.
>
> It would seem that this is your problem. To ensure that the connection
> is promptly detected to be detached, you could either turn on AMQP
> heartbeats or TCP KeepAlive. Either should suffice.
>
> Matthew
> _______________________________________________
> rabbitmq-discuss mailing list
> rabbitmq-discuss at lists.rabbitmq.com
> https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20100921/897868e7/attachment.htm>