[rabbitmq-discuss] Memory leak caused by error_logger in 2.8.6?

Tue Oct 23 00:05:43 BST 2012

Hello,

We're seeing large amounts of memory being used in some of our single
instance 2.8.6 rabbitmq.  When we do a memory
dump, the output appears to say that error_logger is taking up
hundreds of megabytes.  For example:

[{{memory,847631144},
  <4865.6.0>,
  [{registered_name,error_logger},
   {current_function,{gen_event,fetch_msg,5}},
   {initial_call,{proc_lib,init_p,5}},
   {status,waiting},
   {message_queue_len,0},
   {messages,[]},
   {links,[<4865.0.0>,<4865.30.0>]},
   {dictionary,
    [{{xtype_to_module,topic},rabbit_exchange_type_topic},
     {'$ancestors',[<4865.2.0>]},
     {'$initial_call',{gen_event,init_it,6}},
     {guid,{{36630272,1263673450,3038695659,1008081001},3102285}}]},
   {trap_exit,true},
   {error_handler,error_handler},
   {priority,normal},
   {group_leader,<4865.30.0>},
   {total_heap_size,105953765},
   {heap_size,12538050},
   {stack_size,8},
   {reductions,3561515316},
   {garbage_collection,
    [{min_bin_vheap_size,46368},
     {min_heap_size,233},
     {fullsweep_after,65535},
     {minor_gcs,578}]},
   {suspending,[]}]},

(If more of the dump is needed, I can provide)

 We're a bit perplexed as to what's causing this.  There's nothing odd
looking in the logs.  For example, we see stuff like this:

=INFO REPORT==== 22-Oct-2012::18:03:11 ===
accepting AMQP connection <0.1339.402> (127.0.0.1:32803 -> 127.0.0.1:5672)

=WARNING REPORT==== 22-Oct-2012::18:03:11 ===
closing AMQP connection <0.1339.402> (127.0.0.1:32803 -> 127.0.0.1:5672):
connection_closed_abruptly

=INFO REPORT==== 22-Oct-2012::18:03:12 ===
closing AMQP connection <0.1331.402> (127.0.0.1:32796 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:12 ===
accepting AMQP connection <0.1347.402> (127.0.0.1:32840 -> 127.0.0.1:5672)

=WARNING REPORT==== 22-Oct-2012::18:03:13 ===
closing AMQP connection <0.1347.402> (127.0.0.1:32840 -> 127.0.0.1:5672):
connection_closed_abruptly

=INFO REPORT==== 22-Oct-2012::18:03:13 ===
closing AMQP connection <0.32496.401> (127.0.0.1:57108 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:13 ===
closing AMQP connection <0.32476.401> (127.0.0.1:57104 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:13 ===
closing AMQP connection <0.32492.401> (127.0.0.1:57107 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:13 ===
closing AMQP connection <0.32468.401> (127.0.0.1:57103 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:14 ===
accepting AMQP connection <0.1355.402> (127.0.0.1:32875 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:14 ===
closing AMQP connection <0.1355.402> (127.0.0.1:32875 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:15 ===
accepting AMQP connection <0.1363.402> (127.0.0.1:32898 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:15 ===
accepting AMQP connection <0.1371.402> (127.0.0.1:32899 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:15 ===
closing AMQP connection <0.1371.402> (127.0.0.1:32899 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:15 ===
closing AMQP connection <0.32484.401> (127.0.0.1:57106 -> 127.0.0.1:5672)

=INFO REPORT==== 22-Oct-2012::18:03:15 ===
closing AMQP connection <0.32452.401> (127.0.0.1:57081 -> 127.0.0.1:5672)

=WARNING REPORT==== 22-Oct-2012::18:03:15 ===
closing AMQP connection <0.1363.402> (127.0.0.1:32898 -> 127.0.0.1:5672):
connection_closed_abruptly

Is there a way to tell what's really going on with the error_logger
and if we're really generating so many messages that it's causing
memory to balloon so much?

Travis

-- 
Travis Campbell
travis at ghostar.org