[rabbitmq-discuss] Almost all statistics drop to 0 every hour
Irmo Manie
irmo.manie at gmail.com
Tue Nov 13 15:25:08 GMT 2012
Here goes, randomly executed the command. Last 5 calls are done when
publish rate dropped to 0.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,4},
{status,runnable},
{current_stacktrace,[{rabbit_mgmt_db,lookup_element,3,[]},
{rabbit_mgmt_db,handle_stats,6,[]},
{rabbit_mgmt_db,handle_event,2,[]},
{rabbit_mgmt_db,handle_cast,2,[]},
{gen_server,handle_msg,5,
[{file,"gen_server.erl"},{line,597}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,227}]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,1887},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,1040},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,3165},
{status,runnable},
{current_stacktrace,[{dict,update_bkt,4,[{file,"dict.erl"},{line,321}]},
{dict,update_bkt,4,[{file,"dict.erl"},{line,324}]},
{dict,update_bkt,4,[{file,"dict.erl"},{line,324}]},
{dict,on_bucket,3,[{file,"dict.erl"},{line,414}]},
{dict,update,4,[{file,"dict.erl"},{line,317}]},
{lists,foldl,3,[{file,"lists.erl"},{line,1197}]},
{rabbit_mgmt_db,group_sum,2,[]},
{rabbit_mgmt_db,'-fine_stats_fun/2-lc$^0/1-0-',2,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,2423},
{status,runnable},
{current_stacktrace,[{lists,suffix,2,[{file,"lists.erl"},{line,151}]},
{rabbit_mgmt_db,maybe_zero_rate,2,[]},
{rabbit_mgmt_db,'-zero_old_rates/2-lc$^0/1-0-',2,[]},
{rabbit_mgmt_db,'-get_fine_stats_from_list/3-lc$^0/1-0-',
2,[]},
{rabbit_mgmt_db,'-get_fine_stats_from_list/3-lc$^0/1-0-',
2,[]},
{rabbit_mgmt_db,get_fine_stats_from_list,3,[]},
{rabbit_mgmt_db,'-fine_stats_fun/2-lc$^0/1-0-',2,[]},
{rabbit_mgmt_db,'-fine_stats_fun/2-lc$^0/1-0-',2,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,1454},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,0},
{status,waiting},
{current_stacktrace,[{gen_server,loop,6,[{file,"gen_server.erl"},{line,348}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,227}]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,757},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,876},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,1677},
{status,runnable},
{current_stacktrace,[{rabbit_mgmt_db,if_unknown,2,[]},
{rabbit_mgmt_db,gs_update_add,3,[]},
{rabbit_mgmt_db,'-gs_update/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-gs_update/3-lc$^0/1-0-',3,[]},
{lists,foldl,3,[{file,"lists.erl"},{line,1197}]},
{dict,map_bucket,2,[{file,"dict.erl"},{line,459}]},
{dict,map_bucket,2,[{file,"dict.erl"},{line,459}]},
{dict,map_bkt_list,2,[{file,"dict.erl"},{line,455}]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,0},
{status,waiting},
{current_stacktrace,[{gen_server,loop,6,[{file,"gen_server.erl"},{line,348}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,227}]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,735},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,157},
{status,runnable},
{current_stacktrace,[{lists,nthtail,2,[{file,"lists.erl"},{line,127}]},
{lists,suffix,2,[{file,"lists.erl"},{line,153}]},
{rabbit_mgmt_db,maybe_zero_rate,2,[]},
{rabbit_mgmt_db,'-zero_old_rates/2-lc$^0/1-0-',2,[]},
{rabbit_mgmt_db,'-zero_old_rates/2-lc$^0/1-0-',2,[]},
{rabbit_mgmt_db,'-get_fine_stats_from_list/3-lc$^0/1-0-',
2,[]},
{rabbit_mgmt_db,'-get_fine_stats_from_list/3-lc$^0/1-0-',
2,[]},
{rabbit_mgmt_db,get_fine_stats_from_list,3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,0},
{status,waiting},
{current_stacktrace,[{gen_server,loop,6,[{file,"gen_server.erl"},{line,348}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,227}]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,3419},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,3942},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,1940},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,0},
{status,waiting},
{current_stacktrace,[{gen_server,loop,6,[{file,"gen_server.erl"},{line,348}]},
{proc_lib,init_p_do_apply,3,
[{file,"proc_lib.erl"},{line,227}]}]}]
...done.
chvirrmqprd01:~ # rabbitmqctl eval
'process_info(global:whereis_name(rabbit_mgmt_db),
[message_queue_len,status, current_stacktrace]).'
[{message_queue_len,1102},
{status,runnable},
{current_stacktrace,[{mnesia_lib,db_fixtable,3,
[{file,"mnesia_lib.erl"},{line,1127}]},
{mnesia_lib,db_match_object,3,
[{file,"mnesia_lib.erl"},{line,1087}]},
{rpc,local_call,3,[{file,"rpc.erl"},{line,327}]},
{mnesia,do_dirty_rpc,5,
[{file,"mnesia.erl"},{line,1807}]},
{rabbit_mgmt_db,augment_queue_pid,2,[]},
{rabbit_mgmt_db,augment,4,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]},
{rabbit_mgmt_db,'-augment/3-lc$^0/1-0-',3,[]}]}]
...done.
On Tue, Nov 13, 2012 at 3:23 PM, Irmo Manie <irmo.manie at gmail.com> wrote:
> On Tue, Nov 13, 2012 at 12:24 PM, Simon MacMullen <simon at rabbitmq.com>wrote:
>
>> On 13/11/12 10:35, Irmo Manie wrote:
>>
>>> I'm still seeing this behavior and it seems to get worse.
>>> Every hour there is a drop in delivery rate to 0 and now also the
>>> publish rate drops to 0.
>>> Sometimes even for a period of 5 minutes
>>>
>>> I'm really sure that messaging continues and the statistics are a lie.
>>> We use rabbitmq as our main communication hub and certainly a drop in
>>> real-time market data going from ~500 msg/s to 0 for about 5 minutes
>>> must be noticed somewhere if this is true.
>>>
>>> I'm wondering if it might be the writing part of the statistics to the
>>> database. Could that timeout?
>>>
>>
>> No.
>>
>> But if the database is busy with something else then it could take a
>> while to process the updates it's received. I find it hard to believe that
>> it could be busy for 5 minutes though.
>>
>> There is nothing scheduled once an hour in RabbitMQ though - so whatever
>> is happening once an hour must be outside the broker. Figuring out what
>> that is would help a lot.
>>
>>
> Clear :-)
>
>
>>
>> I don't really want to restart to see if that fixes the problem.
>>> It's been running for 177 days now and apart from the weird statistics
>>> we don't have any problems.
>>>
>>> Is there anything I could do as additional checks to figure out where
>>> the problem might be?
>>>
>>
>> Just to be clear: is this just the rates in /api/overview or the ones in
>> /api/queues as well?
>>
>>
> Both show 0 as the rates
>
>
>> I'd also be interested to see the output of:
>>
>> rabbitmqctl eval 'process_info(global:whereis_**name(rabbit_mgmt_db),
>> [message_queue_len,status, current_stacktrace]).'
>>
>> when the statistics drop to 0.
>>
>>
> I'll try to check this and let you know if I find anything weird
>
> Thanks so far for the information and help.
>
> - Irmo
>
>
>>
>> Cheers, Simon
>>
>> --
>> Simon MacMullen
>> RabbitMQ, VMware
>>
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20121113/950e44f5/attachment.htm>
More information about the rabbitmq-discuss
mailing list