[rabbitmq-discuss] RabbitMQ perfomance testing & troubles
Andrew V. Statsenko
alter at tcontest.ru
Wed Apr 16 12:45:53 BST 2008
В Срд, 09/04/2008 в 22:50 +0100, Matthias Radestock пишет:
Hello Matthias !
Fisrt off all many thank for help, second I am very sorry about my bad
written english.
We are continue testing RabbitMQ with Alexey Slynko and here the some
results.
> > Erlang version (stable debian distribution) :
> >
> > # dpkg -l erlang\* | grep ii
> > ii erlang-base 11.b.2-4 Concurrent, real-time, distributed
> > functiona
> > ii erlang-nox 11.b.2-4 Concurrent, real-time, distributed
> > functiona
>
> Any chance you could try the tests with R11B-5? Most of our testing has
> been done on that. I doubt it will make much difference but at the very
> least it will make it easier for us to compare results.
Chance is 100% . Just sey that we are have to rebuild. Current,
backported from Etch, Erlang is:
# dpkg -l erlang\* | grep ii
ii erlang-base 11.b.5dfsg-12 Concurrent, real-time, distributed
functiona
ii erlang-nox 11.b.5dfsg-12 Concurrent, real-time, distributed
functiona
as you say.
> > Another midfications were done for normal mnesia work (errors listed below)
> >
> > ERROR REPORT==== 4-Apr-2008::18:29:14 ===
> > Error in process <0.20713.0> on node 'rabbit at altair' with exit value:
> > {{case_clause,{error,{system_limit,"Cannot create an ets table for
> > the local transaction
> > store",{system_limit,[{ets,new,[mnesia_trans_store,[bag,public]]},{mnesia_tm,doit_loop,1},{mnesia_sp,init_proc,4},{
> >
> > proc_lib...
>
> We have never seen this before. At what point during your tests did you
> get this error?
Test starts, after 7-15 min Erlang eat a lot off memory and give the
errors,
sometime crash.
> These should all be fine except I have some concerns about the "-smp
> auto", given how old a version of Erlang/OTP are running. Did you test
> that adding the flag indeed improves performance?
Yes. Then I use -smp flag the Erlang/OTP eating all 8 CPU core, without
- 1.
>
> Note that RabbitMQ when running with Erlang/OTP R11B (rather than the
> more recent R12) will not benefit much (if at all) from the multiple
> cores when running with -smp. In our experiments we have been getting
> much better results when configuring a local cluster of one non-smp node
> per code. So I'd recommend you do that.
I am newbe man in Erlang/OTP system and correctly configuring a local
cluster
is not easy for me. With SMP mode beam.smp can utilize up to 790% off
this server.
> The following will all impact performance:
>
> - The queues are not auto-deleting and aren't being deleted explicitly,
> and your queue/exchange naming scheme is deterministic. Unless you
> restart the server between tests or subsequent tests will be affected by
> the queues from earlier tests. I'd also recommend clearing the mnesia
> dir prior to starting rabbit, just to make sure that there aren't any
> stray exchanges, queues or persistent messages.
Well,
# invoke-rc.d rabbitmq-server stop
Stopping rabbitmq-server: rabbitmq-server.
# rm -f /var/lib/rabbitmq/mnesia/rabbit/*
# invoke-rc.d rabbitmq-server start
Starting rabbitmq-server: SUCCESS
rabbitmq-server.
>
> - The consumer explicitly acknowledges each message. Would
> bulk-acknowledgment or auto-acknowledgment be an option?
OK, I was delete the acknowledges each message code
- // channel.basicAck(envelope.getDeliveryTag(), false);
start the test
$ java -jar RabbitmqFastMessagingProducerTest.jar 1000 > client.log
after ~ 5 min the server side looks
top - 15:10:19 up 11 days, 21:39, 2 users, load average: 5.93, 2.69,
1.09
Tasks: 115 total, 1 running, 114 sleeping, 0 stopped, 0 zombie
Cpu(s): 58.2%us, 18.9%sy, 0.0%ni, 21.4%id, 0.0%wa, 0.4%hi, 1.1%si,
0.0%st
Mem: 4139508k total, 2233588k used, 1905920k free, 286108k buffers
Swap: 4194296k total, 0k used, 4194296k free, 826336k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
16082 rabbitmq 25 0 1133m 900m 1696 S 615 22.3 16:55.04 beam.smp
23983 rabbitmq 15 0 1828 388 256 S 0 0.0 0:00.00 epmd
16078 rabbitmq 20 0 4172 1548 1080 S 0 0.0 0:00.00
rabbitmq-server
16404 rabbitmq 17 0 1824 472 368 S 0 0.0 0:00.00
inet_gethost
16405 rabbitmq 18 0 1868 592 472 S 0 0.0 0:00.00
inet_gethost
and the client side
$ tail -f client.log | awk '/CLIENT_CONSUMER_THREAD_ID/{print "DELAY: "
$4-$8 " " $0}'
DELAY: 188894 CLIENT_CONSUMER_THREAD_ID: 2 TIME: 1208344442697 MESSAGE:
23 TIME: 1208344253803
DELAY: 187904 CLIENT_CONSUMER_THREAD_ID: 951 TIME: 1208344442697
MESSAGE: 22 TIME: 1208344254793
DELAY: 187807 CLIENT_CONSUMER_THREAD_ID: 871 TIME: 1208344442698
MESSAGE: 22 TIME: 1208344254891
DELAY: 188168 CLIENT_CONSUMER_THREAD_ID: 706 TIME: 1208344442698
MESSAGE: 22 TIME: 1208344254530
DELAY: 188267 CLIENT_CONSUMER_THREAD_ID: 630 TIME: 1208344442698
MESSAGE: 22 TIME: 1208344254431
DELAY: 189608 CLIENT_CONSUMER_THREAD_ID: 626 TIME: 1208344442698
MESSAGE: 23 TIME: 1208344253090
DELAY: 188127 CLIENT_CONSUMER_THREAD_ID: 113 TIME: 1208344442698
MESSAGE: 22 TIME: 1208344254571
DELAY: 188596 CLIENT_CONSUMER_THREAD_ID: 519 TIME: 1208344442698
MESSAGE: 22 TIME: 1208344254102
The delay is about 3 min. I can't understand why.
> You may also want to run one of the test programs supplied with the
> RabbitMQ Java client packages, such as MulticastMain, e.g.
> sh ./runjava.sh com.rabbitmq.examples.MulticastMain -h <host> -a
> which reports on throughput and latency.
Well, the I start signle producer/consumer thread all looks good:
$ sh ./runjava.sh com.rabbitmq.examples.MulticastMain -h host.domain.tld
-a
starting consumer #0
starting producer #0
recving rate: 7780 msg/s, min/avg/max latency: 4083/109443/165431
microseconds
sending rate: 10679 msg/s
recving rate: 9734 msg/s, min/avg/max latency: 109790/135292/163872
microseconds
sending rate: 9821 msg/s
recving rate: 9873 msg/s, min/avg/max latency: 109995/134968/160787
microseconds
sending rate: 9848 msg/s
recving rate: 9969 msg/s, min/avg/max latency: 107159/132702/158851
microseconds
sending rate: 10083 msg/s
recving rate: 9868 msg/s, min/avg/max latency: 108387/134192/160497
microseconds
But, then I start 100 producer/consumer threads latency going to be
high 0.3->20 sec:
$ sh ./runjava.sh com.rabbitmq.examples.MulticastMain
-h host.domain.tld -a -x 100 -y 100 | grep recving
recving rate: 0 msg/s, min/avg/max latency: 11195/11195/11195
microseconds
recving rate: 33217 msg/s, min/avg/max latency: 10113/345828/996901
microseconds
recving rate: 27192 msg/s, min/avg/max latency: 58042/1010474/1997839
microseconds
recving rate: 33569 msg/s, min/avg/max latency: 65700/1562317/2997350
microseconds
recving rate: 24304 msg/s, min/avg/max latency: 90050/2142151/3991946
microseconds
recving rate: 37388 msg/s, min/avg/max latency: 111498/2970700/4996836
microseconds
recving rate: 28715 msg/s, min/avg/max latency: 118559/3476202/5998178
microseconds
recving rate: 28453 msg/s, min/avg/max latency: 144319/4098792/6999516
microseconds
recving rate: 27348 msg/s, min/avg/max latency: 157363/4722565/7998155
microseconds
recving rate: 27508 msg/s, min/avg/max latency: 182090/5381463/9003343
microseconds
recving rate: 27007 msg/s, min/avg/max latency: 192525/6034385/9982716
microseconds
recving rate: 26638 msg/s, min/avg/max latency: 207776/6694654/10998061
microseconds
recving rate: 27001 msg/s, min/avg/max latency: 211793/7335019/12002072
microseconds
recving rate: 26616 msg/s, min/avg/max latency: 244324/7996319/13001783
microseconds
recving rate: 26056 msg/s, min/avg/max latency: 231526/8642121/13997488
microseconds
recving rate: 26521 msg/s, min/avg/max latency: 252036/9327910/15016590
microseconds
recving rate: 26018 msg/s, min/avg/max latency: 262150/10006353/16007951
microseconds
recving rate: 26431 msg/s, min/avg/max latency: 264835/10697607/17017128
microseconds
recving rate: 26018 msg/s, min/avg/max latency: 342075/11366371/18016090
microseconds
recving rate: 25545 msg/s, min/avg/max latency: 273541/11965135/18987288
microseconds
recving rate: 25902 msg/s, min/avg/max latency: 280084/12749721/20008257
microseconds
recving rate: 25449 msg/s, min/avg/max latency: 304305/13347575/21019395
microseconds
recving rate: 25473 msg/s, min/avg/max latency: 309149/13985349/22019055
microseconds
recving rate: 25658 msg/s, min/avg/max latency: 302950/14691935/23020086
microseconds
recving rate: 25564 msg/s, min/avg/max latency: 403575/15483426/24021188
microseconds
recving rate: 25639 msg/s, min/avg/max latency: 323600/15878397/25021019
microseconds
recving rate: 25553 msg/s, min/avg/max latency: 321453/16720349/25974209
microseconds
recving rate: 25747 msg/s, min/avg/max latency: 343184/17436193/27023608
microseconds
recving rate: 24954 msg/s, min/avg/max latency: 386340/17945129/28010304
microseconds
recving rate: 24919 msg/s, min/avg/max latency: 377575/18603424/29026385
microseconds
recving rate: 25226 msg/s, min/avg/max latency: 349285/19401619/30013216
microseconds
recving rate: 25074 msg/s, min/avg/max latency: 491382/20007042/31005415
microseconds
recving rate: 25906 msg/s, min/avg/max latency: 374276/20710481/32014250
microseconds
recving rate: 25153 msg/s, min/avg/max latency: 363636/21417328/33015581
microseconds
Here the result then I run this test in AQMP server host (localhost):
$ sh ./runjava.sh com.rabbitmq.examples.MulticastMain -h localhost -a -x
100 -y 100 | grep recving
recving rate: 0 msg/s, min/avg/max latency: 15532/15532/15532
microseconds
recving rate: 10911 msg/s, min/avg/max latency: 15538/358765/953624
microseconds
recving rate: 19022 msg/s, min/avg/max latency: 86565/907865/2021696
microseconds
recving rate: 18619 msg/s, min/avg/max latency: 116191/1471139/3014532
microseconds
recving rate: 21881 msg/s, min/avg/max latency: 112003/2051780/4021113
microseconds
recving rate: 19014 msg/s, min/avg/max latency: 139058/2687275/4929168
microseconds
recving rate: 18237 msg/s, min/avg/max latency: 184713/3311977/5929642
microseconds
recving rate: 18837 msg/s, min/avg/max latency: 213375/4023915/6917634
microseconds
recving rate: 21111 msg/s, min/avg/max latency: 177935/4640096/7928183
microseconds
recving rate: 16905 msg/s, min/avg/max latency: 167707/5139316/8939816
microseconds
recving rate: 16678 msg/s, min/avg/max latency: 209396/5903245/9921387
microseconds
recving rate: 19055 msg/s, min/avg/max latency: 241024/6477019/10940078
microseconds
recving rate: 17407 msg/s, min/avg/max latency: 309125/7134191/11945223
microseconds
recving rate: 18369 msg/s, min/avg/max latency: 232026/7839258/12949816
microseconds
recving rate: 18599 msg/s, min/avg/max latency: 246842/8434456/13956746
microseconds
recving rate: 18142 msg/s, min/avg/max latency: 261445/9040292/14955231
microseconds
recving rate: 19064 msg/s, min/avg/max latency: 253654/9718233/15976520
microseconds
recving rate: 19028 msg/s, min/avg/max latency: 274436/10391275/16977331
microseconds
recving rate: 17648 msg/s, min/avg/max latency: 339277/11079915/17959945
microseconds
recving rate: 18170 msg/s, min/avg/max latency: 662897/11848865/18972830
microseconds
recving rate: 19169 msg/s, min/avg/max latency: 307943/12328233/19945237
microseconds
recving rate: 17994 msg/s, min/avg/max latency: 342600/13105338/20889999
microseconds
recving rate: 18205 msg/s, min/avg/max latency: 359897/13805425/21926401
microseconds
recving rate: 18324 msg/s, min/avg/max latency: 439293/14389845/22942993
microseconds
recving rate: 16720 msg/s, min/avg/max latency: 409930/15036274/23980343
microseconds
recving rate: 18435 msg/s, min/avg/max latency: 928834/15825577/24938658
microseconds
recving rate: 19078 msg/s, min/avg/max latency: 401601/16257366/25940399
microseconds
recving rate: 17531 msg/s, min/avg/max latency: 445536/17090242/26952144
microseconds
recving rate: 18717 msg/s, min/avg/max latency: 842400/17750288/27990323
microseconds
recving rate: 19389 msg/s, min/avg/max latency: 374073/18312400/28965579
microseconds
It looks strange... like the "reciever" in rabbitmq working match
faster, then "processor" & "sender". Is this result correct ?
WBR,
Alter
More information about the rabbitmq-discuss
mailing list