[rabbitmq-discuss] ERL crashes when messages are being pumped into a queue under win32 envir

Fri Apr 1 03:11:23 BST 2011

My test environment:  receiver and broker running on the same hardware, the broker ran out of memory and not the receiver, since we do not process any messages received.

RabbitMQ's RAM started to increase and fast, far exceeded win32's limitation.  It  does crash at times, but other times,  my receiver and senders would stop working, RabbitMQ would still being shown in the process list, but when use rabbitmqctl to check the state of it, it tells me the node is already down/none existent. 

Also, my sender and receiver memory consumption rather stable, well within our assessment.

Process	           pid      	Physical Mem   		Visual Mem   		  threads
Erl.exe	        		2992		757524K	876384K		41

here is a snippet of the broker log file:

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
Memory limit set to 819MB.

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
Added vhost <<"/">>

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
Created user <<"guest">>

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
Set user admin flag for user <<"guest">> to true

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
msg_store_transient: using rabbit_msg_store_ets_index to provide index

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
msg_store_persistent: using rabbit_msg_store_ets_index to provide index

=WARNING REPORT==== 1-Apr-2011::09:32:13 ===
msg_store_persistent: rebuilding indices from scratch

=INFO REPORT==== 1-Apr-2011::09:32:13 ===
started TCP Listener on 0.0.0.0:9007

=INFO REPORT==== 1-Apr-2011::09:32:25 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5610

=INFO REPORT==== 1-Apr-2011::09:32:25 ===
starting TCP connection <0.255.0> from 192.168.3.43:5610

=INFO REPORT==== 1-Apr-2011::09:32:34 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5611

=INFO REPORT==== 1-Apr-2011::09:32:34 ===
starting TCP connection <0.277.0> from 192.168.3.43:5611

=INFO REPORT==== 1-Apr-2011::09:32:41 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5612

=INFO REPORT==== 1-Apr-2011::09:32:41 ===
starting TCP connection <0.295.0> from 192.168.3.43:5612

=INFO REPORT==== 1-Apr-2011::09:32:48 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5613

=INFO REPORT==== 1-Apr-2011::09:32:48 ===
starting TCP connection <0.312.0> from 192.168.3.43:5613

=INFO REPORT==== 1-Apr-2011::09:32:58 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5614

=INFO REPORT==== 1-Apr-2011::09:32:58 ===
starting TCP connection <0.335.0> from 192.168.3.43:5614

=INFO REPORT==== 1-Apr-2011::09:33:07 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5615

=INFO REPORT==== 1-Apr-2011::09:33:07 ===
starting TCP connection <0.357.0> from 192.168.3.43:5615

=INFO REPORT==== 1-Apr-2011::09:33:09 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5616

=INFO REPORT==== 1-Apr-2011::09:33:09 ===
starting TCP connection <0.367.0> from 192.168.3.43:5616

=INFO REPORT==== 1-Apr-2011::09:33:13 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5617

=INFO REPORT==== 1-Apr-2011::09:33:13 ===
starting TCP connection <0.382.0> from 192.168.3.43:5617

=INFO REPORT==== 1-Apr-2011::09:33:14 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5618

=INFO REPORT==== 1-Apr-2011::09:33:14 ===
starting TCP connection <0.389.0> from 192.168.3.43:5618

=INFO REPORT==== 1-Apr-2011::09:33:22 ===
accepted TCP connection on 0.0.0.0:9007 from 192.168.3.43:5619

=INFO REPORT==== 1-Apr-2011::09:33:22 ===
starting TCP connection <0.409.0> from 192.168.3.43:5619

=INFO REPORT==== 1-Apr-2011::09:37:20 ===
vm_memory_high_watermark set. Memory used:860143728 allowed:858993459

=INFO REPORT==== 1-Apr-2011::09:37:20 ===
    alarm_handler: {set,{{vm_memory_high_watermark,'rabbit at DEV-004'},[]}}

=INFO REPORT==== 1-Apr-2011::09:37:20 ===
vm_memory_high_watermark clear. Memory used:858369128 allowed:858993459

=INFO REPORT==== 1-Apr-2011::09:37:20 ===
    alarm_handler: {clear,{vm_memory_high_watermark,'rabbit at DEV-004'}}

=INFO REPORT==== 1-Apr-2011::09:37:22 ===
vm_memory_high_watermark set. Memory used:859860800 allowed:858993459

=INFO REPORT==== 1-Apr-2011::09:37:22 ===
    alarm_handler: {set,{{vm_memory_high_watermark,'rabbit at DEV-004'},[]}}

thanks

----------------------------------
Ming Li

-----Original Message-----
From: Emile Joubert [mailto:emile at rabbitmq.com] 
Sent: Thursday, March 31, 2011 11:26 PM
To: Ming Li
Cc: rabbitmq-discuss at lists.rabbitmq.com
Subject: Re: [rabbitmq-discuss] ERL crashes when messages are being pumped into a queue under win32 envir

Hi Ming,

On 30/03/11 10:40, Ming Li wrote:
> 1.using RabbitMQ2.4.0(windows bundle).winxp,creates an exchange and a queue.
>
> 2.use multiple sender to send messages into the created queue,only a 
> single receiverreceiving message from the same queue.
>
> 3.while running, what i discovered is that the ERL's RAM usage 
> continue to increase and then crash when it reaches a certain 
> percentage
>
> Is there a way to prevent it from crashing?

Are you sure it's the broker that runs out of memory and not the receiver? Is the receiver and the rabbit broker running on the same hardware?

I see that the channel is not setting QoS. This will cause the broker to deliver messages to the receiver QueueingBasicConsumer as quickly as it can, and the receiver could run out of memory as a result. This is more likely to occur if the consumer is slower than the sender. The solution to this problem is to set the QoS prefetch count (IModel.BasicQos) to a small number and use explicit acknowledgements.

If it really is the broker that runs out of memory could you confirm whether the broker logfile contains entries with both "alarm_handler" 
and "vm_memory_high_watermark"? What else appears in the broker logfile near the time of the crash?

-Emile