[rabbitmq-discuss] RabbitMQ blocking issue

Thu Feb 21 16:25:43 GMT 2013

Matthias,
  Latest attempts:

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

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

0x00007f92bb36dd28 Return addr 0x00007f92ba37dca8 (rabbit_reader:start_connection/7 + 1216)
y(0)     {v1,<0.423.0>,#Port<0.15076>,<<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.424.0>,{<0.435.0>,<0.436.0>},{state,fine,5000,undefined},<0.425.0>,#Fun<rabbit_heartbeat.2.69784259>,[<<12721 bytes>>],12721,rabbit_auth_mechanism_plain,[],false,flow,{1361,463360,568639},{0,0,0,0,0,65535,2756,10773},{0,0,0,0,0,65535,2756,10932},5672,55413}
y(1)     []
y(2)     12721
y(3)     [<<12721 bytes>>]

0x00007f92bb36dd50 Return addr 0x00007f92c0a7da80 (proc_lib:init_p_do_apply/3 + 56)
y(0)     []
y(1)     []
y(2)     []
y(3)     "10.196.42.180:55413 -> 10.196.42.21:5672"
y(4)     #Port<0.15076>
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)

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

Rabbit log:

=INFO REPORT==== 21-Feb-2013::16:04:48 ===
rabbit on node rabbit at ajtrafp064 up

=INFO REPORT==== 21-Feb-2013::16:05:00 ===
accepting AMQP connection <0.418.0> (10.196.42.128:43956 -> 10.196.42.21:5672)

=INFO REPORT==== 21-Feb-2013::16:05:00 ===
accepting AMQP connection <0.422.0> (10.196.42.182:52126 -> 10.196.42.21:5672)

=INFO REPORT==== 21-Feb-2013::16:05:00 ===
accepting AMQP connection <0.426.0> (10.196.42.180:55413 -> 10.196.42.21:5672)

=INFO REPORT==== 21-Feb-2013::16:05:00 ===
accepting AMQP connection <0.430.0> (10.196.42.179:43090 -> 10.196.42.21:5672)

=INFO REPORT==== 21-Feb-2013::16:28:12 ===
Memory limit set to 1MB of 15949MB total.

=INFO REPORT==== 21-Feb-2013::16:28:12 ===
vm_memory_high_watermark set. Memory used:110411552 allowed:1672474

=WARNING REPORT==== 21-Feb-2013::16:28:12 ===
memory resource limit alarm set on node rabbit at ajtrafp063

=INFO REPORT==== 21-Feb-2013::16:28:12 ===
Memory limit set to 6379MB of 15949MB total.

=INFO REPORT==== 21-Feb-2013::16:28:12 ===
vm_memory_high_watermark clear. Memory used:106433744 allowed:6689898496

=WARNING REPORT==== 21-Feb-2013::16:28:12 ===
memory resource limit alarm cleared on node rabbit at ajtrafp063

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.10:20
Type: application/octet-stream
Size: 42050 bytes
Desc: report.pt.10:20
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20130221/bee3414b/attachment.obj>