Hello - <br><br>I'm in the early days of testing RabbitMQ and have been
experiencing the symptoms described below when letting my sample
applications run uninterrupted for 500,000 - 1,000,000 messages or so.
Unfortunately the errors appear inconsistently (ie after different
numbers of consumed messages) and do not always appear on every run.
I've included the output from my client application (very similar to
the ConsumerMain class included in the examples - I've also had the
'read timed out' exception raised when running that class 'as is') as
well as the log contents entries from rabbit at the point of the
exception.
<br><br>Out testing environment is described below.<br><br>2x<br> * 4 core AMD Opteron<br> * 8G memory<br> * eth0 interface with MTU set to 9000<br> * Centos OS - kernel version 2.6.18 <br><br>One
of these machines is the RabbitMQ server and hosts the consumer
application, the other hosts only the producer application. The rabbit
connection and channel are configured as follows.
<br><br>Multiple threads are generating messages from the producer application<br>Version = 1.0.0 alpha<br>Ack sent = yes, every 50 messages<br>framesize = 9000 (our message size is 200 objects * 40 bytes + 12 byte header = 8012 bytes)
<br>queue type = direct
<br>persistent = true (using ChannelN.MINIMAL_PERSISTENT_BASIC_PROPERTIES)<br><div id="mb_0">transactional = false<br><br>This
is designed as a performance test and so is hammering as much load
through the applications as possible. I appreciate that it may be
difficult to diagnose the issue from this description but I would like
to know if this is something that has been seen before or if there is a
way I can modify the level of logging to get more information about the
problems from RabbitMQ itself.
<br><br>Thanks & regards<br><br>James Wolstenholme<br>Software Engineer<br><br><br>==============<br>Connection reset<br>==============<br><br>RabbitMQ log<br><br>=INFO REPORT==== 30-Jul-2007::14:52:05 ===<br>Rolling persister log to "/usr/local/lib/erlang/lib
/rabbitmq-
server-1.0.0-alpha/mnesia/rabbit/rabbit_persister.LOG.previous"<br><br>=ERROR REPORT==== 30-Jul-2007::14:52:42 ===<br>Reader timeout (3 s) in state frame_header<br><br>=INFO REPORT==== 30-Jul-2007::14:53:03 ===<br><
0.166.0>: Clean connection shutdown.<br><br><br>Consumer application stdout<br><br> [java] 117544 ms: Received 210538 - 285 since last report (80 Hz) - objects : 42107600<br> [java] AMQConnection.mainLoop: exception
java.net.SocketException: Connection reset<br> [java] java.net.SocketException: Connection reset<br> [java] at java.net.SocketInputStream.read(SocketInputStream.java:168)<br> [java] at java.net.SocketInputStream.read
(SocketInputStream.java:182)<br> [java] Shutdown signal terminating consumer. com.rabbitmq.client.ShutdownSignal (hard error; reason: java.net.SocketException: Connection reset)<br> [java] at java.io.DataInputStream.readUnsignedByte
(DataInputStream.java:271)<br> [java] at com.rabbitmq.client.Frame.readFrom(Frame.java:84)<br> [java] at com.rabbitmq.client.AMQConnection.readFrame(AMQConnection.java:212)<br> [java] at com.rabbitmq.client.AMQConnection.mainLoop
(AMQConnection.java:239)<br> [java] at com.rabbitmq.client.AMQConnection$1.run(AMQConnection.java:131)<br> [java] at java.lang.Thread.run(Thread.java:619)<br> [java] Channel 1 received shutdown signal:
com.rabbitmq.client.ShutdownSignal (hard error; reason: java.net.SocketException: Connection reset)<br> [java] Channel 0 received shutdown signal:com.rabbitmq.client.ShutdownSignal (hard error; reason: java.net.SocketException
: Connection reset)<br><br><br>============<br>Read timed out<br>============<br><br>RabbitMQ log<br><br>=INFO REPORT==== 30-Jul-2007::15:15:01 ===<br><0.230.0>: Opening channel 1<br><br>=ERROR REPORT==== 30-Jul-2007::15:16:44 ===
<br>Error in process <0.220.0> on node 'rabbit@tfweb01' with exit value: {{badmatch,{error,closed}},[{rabbit_writer,send,2},{rabbit_writer,internal_send_command,5},{rabbit_writer,do_deliver,9},{rabbit_writer,handle_message,2},{rabbit_writer,mainloop,1}]}
<br><br>=ERROR REPORT==== 30-Jul-2007::15:16:44 ===<br>Error in process <0.181.0> on node 'rabbit@tfweb01' with exit value: {{badmatch,{error,enotconn}},[{rabbit_reader,switch_callback,3},{rabbit_reader,mainloop,1},{rabbit_reader,start_connection,1}]}
<br><br>=INFO REPORT==== 30-Jul-2007::15:16:44 ===<br>Requeueing 1 messages, 365175 already on queue<br><br><br>Consumer application stdout<br><br> [java] 101002 ms: Received 66492 - 693 since last report (708 Hz) - objects : 13298400
<br> [java] AMQConnection.mainLoop: exception java.net.SocketTimeoutException: Read timed out<br> [java] java.net.SocketTimeoutException: Read timed out<br> [java] at java.net.SocketInputStream.socketRead0
(Native Method)<br> [java] at java.net.SocketInputStream.read(SocketInputStream.java:129)<br> [java] at java.io.DataInputStream.readFully(DataInputStream.java:178)<br> [java] at java.io.DataInputStream.readFully
(DataInputStream.java:152)<br> [java] at com.rabbitmq.client.Frame.readFrom(Frame.java:101)<br> [java] at com.rabbitmq.client.AMQConnection.readFrame(AMQConnection.java:212)<br> [java] at com.rabbitmq.client.AMQConnection.mainLoop
(AMQConnection.java:239)<br> [java] at com.rabbitmq.client.AMQConnection$1.run(AMQConnection.java:131)<br> [java] at java.lang.Thread.run(Thread.java:619)<br> [java] Channel 1 received shutdown signal:
com.rabbitmq.client.ShutdownSignal (hard error; reason: java.net.SocketTimeoutException: Read timed out)<br> [java] Shutdown signal terminating consumer. com.rabbitmq.client.ShutdownSignal (hard error; reason: java.net.SocketTimeoutException
: Read timed out)<br> [java] Channel 0 received shutdown signal:com.rabbitmq.client.ShutdownSignal (hard error; reason: java.net.SocketTimeoutException: Read timed out)</div>