Erlang/OTP Forums

Author Message

<  RabbitMQ mailing list  ~  persistence

Guest
Posted: Wed May 21, 2008 9:52 am Reply with quote
Guest
Mathias,

after some days of vacation Im going on with rabbitmq. As i wrote last
time the reason why the messages were not sent was because of an
already closed channel.
But still Im not happy with all behaviour and having different issues.
I delayed the time before closing a channel up to 50 seconds. In this
case i was able to send about 150000 messages correctly. If I try to
send more messages I also have to increase the delay time. But if the
communication between producer and broker takes too long i get an
"java.net.SocketException". Here the stacktrace:

hit IOException in Producer: trace follows
java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:96)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
at java.io.DataOutputStream.flush(DataOutputStream.java:106)
at
com.rabbitmq.client.impl.SocketFrameHandler.writeFrame(SocketFrameHandler.java:156)
at
com.rabbitmq.client.impl.AMQConnection.writeFrame(AMQConnection.java:297)
at com.rabbitmq.client.impl.AMQCommand.transmit(AMQCommand.java:190)
at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:369)
at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:350)
at
com.rabbitmq.test.ConcurrentRabbitMQProducerTest.runIt(ConcurrentRabbitMQProducerTest.java:100)
at
com.rabbitmq.test.ConcurrentRabbitMQProducerTest.run(ConcurrentRabbitMQProducerTest.java:71)
at java.lang.Thread.run(Thread.java:619)
Exception in thread "Thread-1" java.lang.RuntimeException:
java.net.SocketException: Connection reset
at
com.rabbitmq.test.ConcurrentRabbitMQProducerTest.run(ConcurrentRabbitMQProducerTest.java:75)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:96)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at
java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:123)
at java.io.DataOutputStream.flush(DataOutputStream.java:106)
at
com.rabbitmq.client.impl.SocketFrameHandler.writeFrame(SocketFrameHandler.java:156)
at
com.rabbitmq.client.impl.AMQConnection.writeFrame(AMQConnection.java:297)
at com.rabbitmq.client.impl.AMQCommand.transmit(AMQCommand.java:190)
at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:369)
at com.rabbitmq.client.impl.ChannelN.basicPublish(ChannelN.java:350)
at
com.rabbitmq.test.ConcurrentRabbitMQProducerTest.runIt(ConcurrentRabbitMQProducerTest.java:100)
at
com.rabbitmq.test.ConcurrentRabbitMQProducerTest.run(ConcurrentRabbitMQProducerTest.java:71)

After this exception also the broker dont respond anymore. The process
is still running but i cant connect with an erlang shell to the
broker. Very strange behaviour. All I can do in this situation is to
restart the broker ...

My System: Im running rabbitmq 1.3. on a gentoo linux. In the log file
is nothing unusal. (How can I actually switch the log level to "debug"
?)

Lars


> Lars,
>
> Matthias Radestock wrote:
>> Lars Bachmann wrote:
>>> by now i tried only 1) and it definitly has some affect. I was
>>> able to send 70000, 100000 and 150000 messages and all were
>>> received by the broker. When i wanted to send 200000 i got a
>>> socketconnection exception.
>>
>> Thanks for running this experiment. These results give me something
>> to go on.
>
> I think I've found the problem, though if my analysis is correct I
> would have expected an error in the server logs. Are you sure there is
> nothing unusual in there? Perhaps you could send me the log output
> recorded by the server when running your test program (in its original
> form, i.e. without the delay in closing the channel).
>
>
> Matthias.





_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 10:57 am Reply with quote
Guest
Lars,

Lars Bachmann wrote:
> Im not happy with all behaviour and having different issues.
> I delayed the time before closing a channel up to 50 seconds. In this
> case i was able to send about 150000 messages correctly. If I try to
> send more messages I also have to increase the delay time.

We know what the problem is here, and it's going to be fixed in the next
release.

> But if the
> communication between producer and broker takes too long i get an
> "java.net.SocketException".

What do you mean by "takes too long"?

> After this exception also the broker dont respond anymore. The process
> is still running but i cant connect with an erlang shell to the broker.
> Very strange behaviour. All I can do in this situation is to restart the
> broker ...

That's strange indeed. RabbitMQ is normally quite difficult to kill Smile

> In the log file is nothing unusal.

Does this go for both the rabbit.log and rabbit-sasl.log?

In any case, please send me the contents of these files.


Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 11:30 am Reply with quote
Guest
Mathias,


>> But if the communication between producer and broker takes too long
>> i get an "java.net.SocketException".
>
> What do you mean by "takes too long"?
>
Too long is the wrong word, lets better say too many messages. But Im
not sure, in my last tests I didnt get this exception, but i got the
"java.lang.IllegalStateException: Attempt to use closed connection"
which is caused by trying to use the already closed channel. But the
point is that even in this case the broker dont respond anymore. My
system shows 100% processor use which is caused by the broker but i
cant connect to the broker anymore.

Both log files are attached. Can u already say when the next release
will be published ?

Lars




Post received from mailinglist
Guest
Posted: Wed May 21, 2008 11:42 am Reply with quote
Guest
Lars,

Lars Bachmann wrote:
> Both log files are attached.

There was only one attachment and it contains just a single message
about the persister log being rolled. That can't be right; there should
be log entries for every client connect and disconnect.

You should have four log files:
rabbit.log
rabbit.log.bak
rabbit-sasl.log
rabbit-sasl.log.bak

Please send me the contents of all of these.


Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 1:32 pm Reply with quote
Guest
> Lars,
>
> Lars Bachmann wrote:
>> Both log files are attached.
>
> There was only one attachment and it contains just a single message
> about the persister log being rolled. That can't be right; there should
> be log entries for every client connect and disconnect.
>
> You should have four log files:
> rabbit.log
> rabbit.log.bak
> rabbit-sasl.log
> rabbit-sasl.log.bak
>
> Please send me the contents of all of these.
>
>
> Matthias.

Mathias,

the log messages i sent you, were created by the communication with
one client where the error occurs. However i made some more actions
and Im sending u the files now. The "sasl" files are always empty but
in the log files is one error message. I hope it ll help you.

Lars



Post received from mailinglist
Guest
Posted: Wed May 21, 2008 2:33 pm Reply with quote
Guest
Lars Bachmann wrote:
> the log messages i sent you, were created by the communication with one
> client where the error occurs. However i made some more actions and Im
> sending u the files now. The "sasl" files are always empty but in the
> log files is one error message.

I do not see any error messages in the log files. Also, there is still
no trace of the TCP listener starting, or the client
connecting/disconnecting, which is extremely weird.

How exactly are you starting the broker?

Are you running a cluster?

One thing to try is to get an erlang shell in your broker and evaluate
rabbit_log:info("show me!").
and then check whether the message appears in the rabbit log.

It would also be useful if you ran a clean test. Stop the broker remove
the mnesia dir and log files. Start the broker. Then run your tests. And
then send me the log files.


Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 2:45 pm Reply with quote
Guest
Zitat von Matthias Radestock <matthias@lshift.net>:

> Lars Bachmann wrote:
>> the log messages i sent you, were created by the communication with
>> one client where the error occurs. However i made some more
>> actions and Im sending u the files now. The "sasl" files are
>> always empty but in the log files is one error message.
>
> I do not see any error messages in the log files. Also, there is still
> no trace of the TCP listener starting, or the client
> connecting/disconnecting, which is extremely weird.
>
> How exactly are you starting the broker?
>
> Are you running a cluster?
>
> One thing to try is to get an erlang shell in your broker and evaluate
> rabbit_log:info("show me!").
> and then check whether the message appears in the rabbit log.
>
> It would also be useful if you ran a clean test. Stop the broker remove
> the mnesia dir and log files. Start the broker. Then run your tests.
> And then send me the log files.
>
>
> Matthias.

the error message is in the broker4.log.bak file and it says:

=ERROR REPORT==== 21-May-2008::13:22:48 ===
Error in process <0.166.0> on node 'broker4@vmpontos' with exit value:
{badarg,[{erlang,port_command,[#Port<0.258>,[<<7 bytes>>,<<4
bytes>>,<<1
byte>>]]},{rabbit_writer,internal_send_command_async,3},{rabbit_writer,handle_message,2},{rabbit_writer,mainloop,1}]}

and there are also messages about tcp connections (for example):

=INFO REPORT==== 21-May-2008::13:15:39 ===
started TCP listener on 10.1.2.130:5672

I run your test with log info and the text showed up in the logs and
no, i dont run a cluster. I ll ran a clean test now and send u the
result.

Lars



_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 3:06 pm Reply with quote
Guest
Lars,

Lars Bachmann wrote:

> the error message is in the broker4.log.bak file and it says:
>
> =ERROR REPORT==== 21-May-2008::13:22:48 ===
> Error in process <0.166.0> on node 'broker4@vmpontos' with exit value:
> {badarg,[{erlang,port_command,[#Port<0.258>,[<<7 bytes>>,<<4 bytes>>,<<1
> byte>>]]},{rabbit_writer,internal_send_command_async,3},{rabbit_writer,handle_message,2},{rabbit_writer,mainloop,1}]}
>
> and there are also messages about tcp connections (for example):
>
> =INFO REPORT==== 21-May-2008::13:15:39 ===
> started TCP listener on 10.1.2.130:5672

Those messages are not in the log files you sent me. See for yourself at
http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/2008-May/001264.html

> I run your test with log info and the text showed up in the logs and no,
> i dont run a cluster. I ll ran a clean test now and send u the result.

Thanks. Just make sure to attach the complete logs in your report Smile


Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 3:11 pm Reply with quote
Guest
Mathias,

here a short description of what i did and what exactly happened:

1. i stoped the broker, removed all stored messages and the logfiles
and restarted the broker
2. my client is set up to wait 50 seconds after sending all messages
before the channel will be closed
3. Im sending 500000 messages to the broker. 50 seconds seem to be to
short thats why only 120000 messages are received by the broker => no
client exception
4. Im sending again 500000 messages, some (of coz not all) messages
are sent and then an exceptions occurs
(java.lang.IllegalStateException: Attempt to use closed channel)
5. when i try to send one more time 500000 messages i get the
socketexception immediatly and the broker is not reachable anymore and
i have to kill the process

the log file is attached (in the sasl log file are no entries and
there are no bak log files because i removed all on startup)

Lars





Post received from mailinglist
Guest
Posted: Wed May 21, 2008 3:33 pm Reply with quote
Guest
Lars,

Lars Bachmann wrote:
> the log file is attached

Once again the log file you sent contains just a single entry. Something
must be going wrong when you attach these files to your emails.


Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Wed May 21, 2008 4:36 pm Reply with quote
Guest
Zitat von Matthias Radestock <matthias@lshift.net>:

> Lars,
>
> Lars Bachmann wrote:
>> the log file is attached
>
> Once again the log file you sent contains just a single entry.
> Something must be going wrong when you attach these files to your
> emails.
>
>
> Matthias.

oh sorry all my fault, i set up the broker on my computer and also on
a vm. both locate the log files at the same position, but i sent u the
files from my comp and not from the vm where Im running all my tests.
how stupid Smile ok here we go ...

but i dont think there is something that could help u in the messages Sad

Lars



Post received from mailinglist
Guest
Posted: Thu May 22, 2008 8:31 am Reply with quote
Guest
Mathias,

I made some more tests (changing the delay time before the channel
shut down, changing number of messages to sent) and I think the
problem is always the closed channel. Sometimes when the channel is
closed before all messages are sent the result is that not all
messages are received by the broker, sometimes the client throws an
"IllegalStateException Attempt to use closed channel" and sometimes
even the broker is affeted and dont respond anymore. (For me it is
also very strange why sometimes from lets say 200000 messages 100000
are sent and sometimes only 15000. Is there some buffering for
messages before sending ?)

Anyway u mentioned that u know this problem with the closed channel
and u re working on it and it ll be fixed with the next release. Can u
say when the next release will be published ? (some weeks, months,
years Wink)

In our company we comparing different messaging solutions and rabbitmq
seemed to be a good one, but the problems with the presistent messages
are unfortunatelly a big minus.

Lars



_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Thu May 22, 2008 9:09 am Reply with quote
Guest
Lars,

Lars Bachmann wrote:
> Anyway u mentioned that u know this problem with the closed channel and
> u re working on it and it ll be fixed with the next release. Can u say
> when the next release will be published ? (some weeks, months, years Wink)

We hope to have a new release in a few weeks.

> In our company we comparing different messaging solutions and rabbitmq
> seemed to be a good one, but the problems with the presistent messages
> are unfortunatelly a big minus.

The problem actually isn't with persistent messaging, but with sending
lots of messages at a rate greater than the broker can process, and
building up backlogs of 10th of thousands of messages in doing do.
Persistence increases the workload and thus lowers the processing rate,
which makes the problem more noticeable when persistence is enabled.

The bug is not causing any difficulties in practice unless *all* of the
following are true of your clients:
- they publish messages to the broker at a rate that significantly
exceeds the brokers processing capacity
- they sustain such a rate for a significant period of time (i.e. not
just a few second blip)
- they disconnect shortly after sending all these messages

Regards,

Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Thu May 22, 2008 12:50 pm Reply with quote
Guest
Lars,

Matthias Radestock wrote:
> Lars Bachmann wrote:
>> In our company we comparing different messaging solutions and rabbitmq
>> seemed to be a good one, but the problems with the presistent messages
>> are unfortunatelly a big minus.
>
> The problem actually isn't with persistent messaging, but with sending
> lots of messages at a rate greater than the broker can process, and
> building up backlogs of 10th of thousands of messages in doing do.
> Persistence increases the workload and thus lowers the processing rate,
> which makes the problem more noticeable when persistence is enabled.
>
> The bug is not causing any difficulties in practice unless *all* of the
> following are true of your clients:
> - they publish messages to the broker at a rate that significantly
> exceeds the brokers processing capacity
> - they sustain such a rate for a significant period of time (i.e. not
> just a few second blip)
> - they disconnect shortly after sending all these messages

I forgot to mention that this is actually a grey area in the AMQP spec.
What RabbitMQ is doing is perfectly compliant. We have initiated a
discussion in the the AMQP working group to get the spec clarified.
Independently of that, as I mentioned, we will fix the the problem in
the next release.

I should also point out that AMQP's basic.publish is fundamentally
asynchronous and thus limited in the guarantees it provides. You get
stronger guarantees when wrapping your publish requests in transactions
(see channel.tx{Select,Commit,Rollback}() in the Java API). The server
guarantees that persistent messages have been written to disk by the
time it returns tx.commit-ok, though obviously this carries a
performance penalty.


Matthias.

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist
Guest
Posted: Thu May 22, 2008 4:06 pm Reply with quote
Guest
Mathias,

thank you for your help and all the information you gave me. Now my
task is to check some other mq brokers and in the end we ll see which
system fits our requirements the best. The work with rabbitmq was all
in all very satisfying except this channel bug. I hope it ll be fixed
soon, but let's first have a look on the problems of the other brokers
Wink.

One more question. In the roadmap the jms integration is mentioned.
Will this be also realized in the next release of rabbitmq ?

Lars

> Lars,
>
> Matthias Radestock wrote:
>> Lars Bachmann wrote:
>>> In our company we comparing different messaging solutions and
>>> rabbitmq seemed to be a good one, but the problems with the
>>> presistent messages are unfortunatelly a big minus.
>>
>> The problem actually isn't with persistent messaging, but with
>> sending lots of messages at a rate greater than the broker can
>> process, and building up backlogs of 10th of thousands of messages
>> in doing do. Persistence increases the workload and thus lowers the
>> processing rate, which makes the problem more noticeable when
>> persistence is enabled.
>>
>> The bug is not causing any difficulties in practice unless *all* of
>> the following are true of your clients:
>> - they publish messages to the broker at a rate that significantly
>> exceeds the brokers processing capacity
>> - they sustain such a rate for a significant period of time (i.e.
>> not just a few second blip)
>> - they disconnect shortly after sending all these messages
>
> I forgot to mention that this is actually a grey area in the AMQP spec.
> What RabbitMQ is doing is perfectly compliant. We have initiated a
> discussion in the the AMQP working group to get the spec clarified.
> Independently of that, as I mentioned, we will fix the the problem in
> the next release.
>
> I should also point out that AMQP's basic.publish is fundamentally
> asynchronous and thus limited in the guarantees it provides. You get
> stronger guarantees when wrapping your publish requests in transactions
> (see channel.tx{Select,Commit,Rollback}() in the Java API). The server
> guarantees that persistent messages have been written to disk by the
> time it returns tx.commit-ok, though obviously this carries a
> performance penalty.
>
>
> Matthias.





_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss@lists.rabbitmq.com
http://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Post received from mailinglist

Display posts from previous:  

All times are GMT
Page 2 of 3
Goto page Previous  1, 2, 3  Next
This forum is locked: you cannot post, reply to, or edit topics.

Jump to:  

You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum
You cannot attach files in this forum
You cannot download files in this forum