[rabbitmq-discuss] rabbit_limiter Exception and Broker Issues
Chris Larsen
clarsen at euphoriaaudio.com
Mon Dec 16 20:24:19 GMT 2013
Hiya, we ran into some problems with a cluster over the weekend. There was a
sharp increase in message publishing traffic to this 2 node cluster that
increased memory and FD usage but we didn't observe the normal limit
messages in the logs. Instead we say this "rabbit_limiter" exception and the
nodes stopped accepting published messages. Thankfully we were able to
consume the queued, in-memory, data before restarting the nodes. Did we
simply throw too many messages at Rabbit or was there an actual bug in the
limiter code? We're running 3.1.5 with Erlang R16B01 on both nodes. Below
are some bits from the main logs on both nodes and the full SASL logs are in
pastebin. Thanks!
Node 1 sasl
http://pastebin.com/h55i3AqQ
Node 2 sasl
http://pastebin.com/3hw7f6xA
------ NODE1 Rabbit LOG ------
=ERROR REPORT==== 14-Dec-2013::11:39:15 ===
** Generic server <0.21763.1353> terminating
** Last message in was stat
** When Server state == {lim,0,<0.26407.1167>,false,[],0}
** Reason for termination ==
** {function_clause,[{rabbit_limiter,handle_call,
[stat,
{<0.234.0>,#Ref<0.0.8426.115176>},
{lim,0,<0.26407.1167>,false,[],0}],
[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,239}]}]}
=ERROR REPORT==== 14-Dec-2013::11:55:10 ===
** Generic server <0.28277.6695> terminating
** Last message in was {'$gen_cast',
{method,
{'queue.declare',0,
<<"notification.somehost">>,
false,false,false,false,false,
[{<<"x-expires">>,signedint,10800000}]},
none,noflow}}
** When Server state == {ch,running,rabbit_framing_amqp_0_9_1,247,
<0.4536.6658>,<0.13044.6658>,<0.4536.6658>,
<<C_IP -> S_IP>>,
{lstate,<0.20106.6569>,false,false},
none,1,
{[],[]},
{user,<<"app_user">>,
[administrator],
rabbit_auth_backend_internal,
{internal_user,<<"app_user">>,
<<79,159,188,106,120,27,224,243,230,15,223,
54,140,137,70,36,212,30,111,89>>,
[administrator]}},
<<"/app_user">>,<<>>,
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{set,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{set,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
<0.8820.6668>,
{state,fine,5000,#Ref<0.0.6989.167017>},
false,1,
{{0,nil},{0,nil}},
[],
[{<<"consumer_cancel_notify">>,bool,true},
{<<"publisher_confirms">>,bool,true}],
none}
** Reason for termination ==
** {{{function_clause,
[{supervisor2,handle_call,
[stat,
{<7347.227.0>,#Ref<7347.0.8145.90172>},
{state,
{<7347.9746.1239>,rabbit_intermediate_sup},
one_for_one,[],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},
10,10,[],rabbit_intermediate_sup,[]}],
[]},
{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},
{gen_server2,call,[<7347.9746.1239>,stat,infinity]}},
[{gen_server2,call,3,[]},
{delegate,safe_invoke,2,[]},
{delegate,'-safe_invoke/2-lc$^0/1-0-',2,[]},
{delegate,handle_call,3,[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,249}]}]}
=ERROR REPORT==== 14-Dec-2013::11:55:10 ===
AMQP connection <0.4536.6658> (running), channel 247 - error:
{{{function_clause,
[{supervisor2,handle_call,
[stat,
{<7347.227.0>,#Ref<7347.0.8145.90172>},
{state,
{<7347.9746.1239>,rabbit_intermediate_sup},
one_for_one,[],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},
10,10,[],rabbit_intermediate_sup,[]}],
[]},
{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},
{gen_server2,call,[<7347.9746.1239>,stat,infinity]}},
[{gen_server2,call,3,[]},
{delegate,safe_invoke,2,[]},
{delegate,'-safe_invoke/2-lc$^0/1-0-',2,[]},
{delegate,handle_call,3,[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,249}]}]}
=WARNING REPORT==== 14-Dec-2013::11:55:10 ===
Non-AMQP exit reason '{{{function_clause,
[{supervisor2,handle_call,
[stat,
{<7347.227.0>,#Ref<7347.0.8145.90172>},
{state,
{<7347.9746.1239>,rabbit_intermediate_sup},
one_for_one,[],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]}}},
10,10,[],rabbit_intermediate_sup,[]}],
[]},
{gen_server,handle_msg,5,
[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,239}]}]},
{gen_server2,call,[<7347.9746.1239>,stat,infinity]}},
[{gen_server2,call,3,[]},
{delegate,safe_invoke,2,[]},
{delegate,'-safe_invoke/2-lc$^0/1-0-',2,[]},
{delegate,handle_call,3,[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,wake_up,3,
[{file,"proc_lib.erl"},{line,249}]}]}'
=ERROR REPORT==== 14-Dec-2013::12:27:35 ===
** Generic server <0.17415.2019> terminating
** Last message in was {'$gen_cast',
{method,
{'queue.declare',0,
<<"notification.somehost">>,
false,false,false,false,false,
[{<<"x-expires">>,signedint,10800000}]},
none,noflow}}
** When Server state == {ch,running,rabbit_framing_amqp_0_9_1,240,
<0.23804.2237>,<0.9694.2017>,<0.23804.2237>,
<<C_IP -> S_IP>>,
{lstate,<0.8750.2014>,false,false},
none,1,
{[],[]},
{user,<<"app_user">>,
[administrator],
rabbit_auth_backend_internal,
{internal_user,<<"app_user">>,
<<199,64,175,52,127,65,248,9,70,171,15,9,5,
122,73,4,195,147,238,67>>,
[administrator]}},
<<"/app_user">>,<<>>,
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{set,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
{set,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[]}}},
<0.6852.2217>,
{state,fine,5000,#Ref<0.0.8928.158612>},
false,1,
{{0,nil},{0,nil}},
[],
[{<<"consumer_cancel_notify">>,bool,true},
{<<"publisher_confirms">>,bool,true}],
none}
** Reason for termination ==
** {{{function_clause,
[{supervisor2,handle_call,
[stat,
{<7347.226.0>,#Ref<7347.0.8518.17139>},
{state,
{<7347.8508.1220>,rabbit_connection_sup},
one_for_all,
[{child,<7347.27376.2037>,reader,
{rabbit_reader,start_link,
[<7347.29450.2047>,<7347.19330.2055>,
#Fun<rabbit_heartbeat.2.69784259>]},
intrinsic,4294967295,worker,
[rabbit_reader]},
{child,<7347.29450.2047>,channel_sup3,
{rabbit_intermediate_sup,start_link,[]},
intrinsic,infinity,supervisor,
[rabbit_intermediate_sup]},
{child,<7347.19330.2055>,collector,
{rabbit_queue_collector,start_link,[]},
intrinsic,4294967295,worker,
[rabbit_queue_collector]}],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},
0,1,[],rabbit_connection_sup,[]}],
[]},
{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},
{gen_server2,call,[<7347.8508.1220>,stat,infinity]}},
[{gen_server2,call,3,[]},
{delegate,safe_invoke,2,[]},
{delegate,'-safe_invoke/2-lc$^0/1-0-',2,[]},
{delegate,handle_call,3,[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,249}]}]}
=ERROR REPORT==== 14-Dec-2013::12:27:35 ===
AMQP connection <0.23804.2237> (running), channel 240 - error:
{{{function_clause,
[{supervisor2,handle_call,
[stat,
{<7347.226.0>,#Ref<7347.0.8518.17139>},
{state,
{<7347.8508.1220>,rabbit_connection_sup},
one_for_all,
[{child,<7347.27376.2037>,reader,
{rabbit_reader,start_link,
[<7347.29450.2047>,<7347.19330.2055>,
#Fun<rabbit_heartbeat.2.69784259>]},
intrinsic,4294967295,worker,
[rabbit_reader]},
{child,<7347.29450.2047>,channel_sup3,
{rabbit_intermediate_sup,start_link,[]},
intrinsic,infinity,supervisor,
[rabbit_intermediate_sup]},
{child,<7347.19330.2055>,collector,
{rabbit_queue_collector,start_link,[]},
intrinsic,4294967295,worker,
[rabbit_queue_collector]}],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},
0,1,[],rabbit_connection_sup,[]}],
[]},
{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},
{gen_server2,call,[<7347.8508.1220>,stat,infinity]}},
[{gen_server2,call,3,[]},
{delegate,safe_invoke,2,[]},
{delegate,'-safe_invoke/2-lc$^0/1-0-',2,[]},
{delegate,handle_call,3,[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,249}]}]}
=WARNING REPORT==== 14-Dec-2013::12:27:35 ===
Non-AMQP exit reason '{{{function_clause,
[{supervisor2,handle_call,
[stat,
{<7347.226.0>,#Ref<7347.0.8518.17139>},
{state,
{<7347.8508.1220>,rabbit_connection_sup},
one_for_all,
[{child,<7347.27376.2037>,reader,
{rabbit_reader,start_link,
[<7347.29450.2047>,<7347.19330.2055>,
#Fun<rabbit_heartbeat.2.69784259>]},
intrinsic,4294967295,worker,
[rabbit_reader]},
{child,<7347.29450.2047>,channel_sup3,
{rabbit_intermediate_sup,start_link,[]},
intrinsic,infinity,supervisor,
[rabbit_intermediate_sup]},
{child,<7347.19330.2055>,collector,
{rabbit_queue_collector,start_link,[]},
intrinsic,4294967295,worker,
[rabbit_queue_collector]}],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],
[]}}},
0,1,[],rabbit_connection_sup,[]}],
[]},
{gen_server,handle_msg,5,
[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,239}]}]},
{gen_server2,call,[<7347.8508.1220>,stat,infinity]}},
[{gen_server2,call,3,[]},
{delegate,safe_invoke,2,[]},
{delegate,'-safe_invoke/2-lc$^0/1-0-',2,[]},
{delegate,handle_call,3,[]},
{gen_server2,handle_msg,2,[]},
{proc_lib,wake_up,3,
[{file,"proc_lib.erl"},{line,249}]}]}'
------ NODE2 Rabbit LOG ------
=ERROR REPORT==== 14-Dec-2013::11:55:10 ===
** Generic server <0.9746.1239> terminating
** Last message in was stat
** When Server state == {state,{<0.9746.1239>,rabbit_intermediate_sup},
one_for_one,[],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],
[],[],[]}}},
10,10,[],rabbit_intermediate_sup,[]}
** Reason for termination ==
** {function_clause,
[{supervisor2,handle_call,
[stat,
{<0.227.0>,#Ref<0.0.8145.90172>},
{state,
{<0.9746.1239>,rabbit_intermediate_sup},
one_for_one,[],
{dict,0,16,16,8,80,48,
{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},
{{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]}}},
10,10,[],rabbit_intermediate_sup,[]}],
[]},
{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,585}]},
{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]}
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20131216/1babfc3a/attachment.html>
More information about the rabbitmq-discuss
mailing list