[rabbitmq-discuss] RabbitMQ blocking issue

Thu Feb 21 17:24:03 GMT 2013

In talking with Daniel, he wants to inform you that the nature of the traffic is burst of 78K messages across 4 nodes on the minute mark to a single rabbit.

One more trace:
[pkonar at ajtrafp063 rabbitmq]$ sudo rabbitmqctl -q list_connections pid peer_port | grep 52126
<rabbit at ajtrafp063.1.422.0>     52126
[pkonar at ajtrafp063 rabbitmq]$ sudo rabbitmqctl eval '{backtrace, B} =process_info(rabbit_misc:string_to_pid("<rabbit at ajtrafp063.1.422.0>"),backtrace), io:format("~s", [binary_to_list(B)]).'
Program counter: 0x00007f92ba5036d8 (rabbit_net:recv/2 + 136)
CP: 0x0000000000000000 (invalid)
arity = 0

0x00007f92c2040608 Return addr 0x00007f92ba37e6d0 (rabbit_reader:mainloop/2 + 248)
y(0)     #Port<0.15075>
y(1)     tcp_error
y(2)     tcp_closed
y(3)     tcp

0x00007f92c2040630 Return addr 0x00007f92ba37dca8 (rabbit_reader:start_connection/7 + 1216)
y(0)     {v1,<0.419.0>,#Port<0.15075>,<<40 bytes>>,{connection,rabbit_framing_amqp_0_9_1,{user,<<5 bytes>>,[administrator],rabbit_auth_backend_internal,{internal_user,<<5 bytes>>,<<20 bytes>>,[administrator]}},600,131072,<<1 byte>>,[{<<7 bytes>>,longstr,<<8 bytes>>},{<<11 bytes>>,longstr,<<52 bytes>>},{<<8 bytes>>,longstr,<<4 bytes>>},{<<12 bytes>>,table,[{<<26 bytes>>,bool,true},{<<22 bytes>>,bool,true},{<<10 bytes>>,bool,true},{<<18 bytes>>,bool,true}]},{<<9 bytes>>,longstr,<<36 bytes>>},{<<7 bytes>>,longstr,<<5 bytes>>}],[{<<26 bytes>>,bool,true},{<<22 bytes>>,bool,true},{<<10 bytes>>,bool,true},{<<18 bytes>>,bool,true}]},frame_header,7,false,running,<0.420.0>,{<0.433.0>,<0.434.0>},{state,fine,5000,undefined},<0.421.0>,#Fun<rabbit_heartbeat.2.69784259>,[<<4458 bytes>>],4458,rabbit_auth_mechanism_plain,[],false,flow,{1361,466181,586431},{0,0,0,0,0,65535,2756,10773},{0,0,0,0,0,65535,2756,10934},5672,52126}
y(1)     []
y(2)     4458
y(3)     [<<4458 bytes>>]

0x00007f92c2040658 Return addr 0x00007f92c0a7da80 (proc_lib:init_p_do_apply/3 + 56)
y(0)     []
y(1)     []
y(2)     []
y(3)     "10.196.42.182:52126 -> 10.196.42.21:5672"
y(4)     #Port<0.15075>
y(5)     []
y(6)     []
y(7)     []
y(8)     []
y(9)     Catch 0x00007f92ba37dd28 (rabbit_reader:start_connection/7 + 1344)
y(10)    Catch 0x00007f92ba37df10 (rabbit_reader:start_connection/7 + 1832)

0x00007f92c20406b8 Return addr 0x00000000008827d8 (<terminate process normally>)
y(0)     Catch 0x00007f92c0a7daa0 (proc_lib:init_p_do_apply/3 + 88)
ok
...done.

Thanks
Peter Konar

________________________________________
From: ext Matthias Radestock [matthias at rabbitmq.com]
Sent: Thursday, February 21, 2013 9:21 AM
To: Konar Peter (Nokia-LC/Chicago)
Cc: Carroll James (Nokia-LC/Malvern); Hancock Craig (Nokia-LC/Chicago); Venus Justin (Nokia-LC/Chicago); Yu Jerry.3 (Nokia-LC/Alpharetta); Lieber Dick (Nokia-LC/Chicago); Johnson Anthony (Nokia-LC/Alpharetta); Mccuiston Mitchell (Nokia-LC/Chicago); rabbitmq-discuss at lists.rabbitmq.com
Subject: Re: [rabbitmq-discuss] RabbitMQ blocking issue

(re-sending since the m/l had dropped off the 'cc')

Peter,

On 21/02/13 14:55, Konar Peter (Nokia-LC/Chicago) wrote:
> from the log:
>
> =ERROR REPORT==== 21-Feb-2013::14:01:02 ===
> closing AMQP connection <0.23035.17> (10.196.42.128:59179 -> 10.196.42.21:5672):
> {heartbeat_timeout,running}
>
> =INFO REPORT==== 21-Feb-2013::14:01:02 ===
> accepting AMQP connection <0.23611.34> (10.196.42.128:41413 -> 10.196.42.21:5672)
>
> =INFO REPORT==== 21-Feb-2013::14:06:28 ===
> Memory limit set to 1MB of 15949MB total.
>
> =INFO REPORT==== 21-Feb-2013::14:06:28 ===
> vm_memory_high_watermark set. Memory used:141211416 allowed:1672474
>
> =WARNING REPORT==== 21-Feb-2013::14:06:28 ===
> memory resource limit alarm set on node rabbit at ajtrafp063
>
> =INFO REPORT==== 21-Feb-2013::14:06:38 ===
> Memory limit set to 6379MB of 15949MB total.
>
> =INFO REPORT==== 21-Feb-2013::14:06:38 ===
> vm_memory_high_watermark clear. Memory used:129010184 allowed:6689898496
>
> =WARNING REPORT==== 21-Feb-2013::14:06:38 ===
> memory resource limit alarm cleared on node rabbit at ajtrafp063

Looks like you got there too late - the connection timed out before the
'rabbitmqctl set_vm_memory_high_watermark ...' commands.

Hopefully you'll catch it early enough next time.

Also, before you run the pair of 'rabbitmqctl
set_vm_memory_high_watermark ...' commands, do the following:

1) determine the pid of the connection that is blocked by running
   rabbitmqctl -q list_connections pid peer_port | grep <port>
where <port> is the peer port shown in the netstat output, e.g. 59179 in
the case we've just looked at.

2) plug the pid, which looks something like <rabbit at host.1.289.0>, into
   rabbitmqctl eval '{backtrace, B} =
process_info(rabbit_misc:string_to_pid("<rabbit at host.1.289.0>"),
backtrace), io:format("~s", [binary_to_list(B)]).'
(all on one line) and post the output. NB: If you are in a cluster, you
need to run this on the rabbit server identified by the host portion of
the pid.

Regards,

Matthias.

The information contained in this communication may be CONFIDENTIAL and is intended only for the use of the recipient(s) named above.  If you are not the intended recipient, you are hereby notified that any dissemination, distribution, or copying of this communication, or any of its contents, is strictly prohibited.  If you have received this communication in error, please notify the sender and delete/destroy the original message and any copy of it from your computer or paper files.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: report.pt.11:10
Type: application/octet-stream
Size: 42955 bytes
Desc: report.pt.11:10
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20130221/1ab9a2e1/attachment.obj>