5 Replies Latest reply on Jan 14, 2012 3:54 AM by Michael Justin

    STOMP - alternating low/high transfer rates

    Michael Justin Novice

      Hello,

       

      I have set up a STOMP client test application for HornetQ (2.2.5.Final on Windows Vista) which runs two threads, one is continuously sending messages to a topic, and the other consumes them, using client-side ack.

       

      If the test application runs the first time after launching the broker, the test shows quite low message rates as shown below, and the CPU load is minimal. (Note that there are timeouts too (the timeout limit is set to 5000 milliseconds).

       

      But when I terminate the test application - not the broker - and start again the transfer rates are very high - more than 5000 messages per second, and I also see higher CPU load.

       

      The next run then has low rates, but eventually with very high rates for outgoing (to broker) messages.

       

      This looks strange and maybe there are settings which control the balancing between incoming and outgoing messages?

       

      00:02 tx/rx: 2895/2186 - 1090 msgs/sec (917 microsecs/roundtrip)

      00:04 tx/rx: 3590/2866 - 715 msgs/sec (1398 microsecs/roundtrip)

      00:06 tx/rx: 4419/3787 - 630 msgs/sec (1587 microsecs/roundtrip)

      00:08 tx/rx: 5067/4319 - 539 msgs/sec (1855 microsecs/roundtrip)

      00:10 tx/rx: 7564/7014 - 701 msgs/sec (1426 microsecs/roundtrip)

      00:12 tx/rx: 8536/8074 - 672 msgs/sec (1488 microsecs/roundtrip)

      00:14 tx/rx: 9538/9053 - 646 msgs/sec (1547 microsecs/roundtrip)

      00:16 tx/rx: 11199/10717 - 669 msgs/sec (1494 microsecs/roundtrip)

      00:18 tx/rx: 12947/12205 - 677 msgs/sec (1477 microsecs/roundtrip)

      00:20 tx/rx: 13757/12925 - 646 msgs/sec (1547 microsecs/roundtrip)

      00:22 tx/rx: 14891/14325 - 650 msgs/sec (1538 microsecs/roundtrip)

      00:24 tx/rx: 16511/15781 - 657 msgs/sec (1522 microsecs/roundtrip)

      00:26 tx/rx: 17615/15781 - 606 msgs/sec (1650 microsecs/roundtrip)

      00:28 tx/rx: 17772/15781 - 563 msgs/sec (1776 microsecs/roundtrip)

      ReceiveThread: TCP/IP Socket error 10060: Connection timed out

      00:30 tx/rx: 17772/15781 - 525 msgs/sec (1904 microsecs/roundtrip)

      00:32 tx/rx: 17772/15781 - 493 msgs/sec (2028 microsecs/roundtrip)

      SendThread: TCP/IP Socket error 10060: Connection timed out

      00:34 tx/rx: 17773/15781 - 464 msgs/sec (2155 microsecs/roundtrip)

      00:36 tx/rx: 22471/15781 - 438 msgs/sec (2283 microsecs/roundtrip)

      00:38 tx/rx: 33890/15781 - 415 msgs/sec (2409 microsecs/roundtrip)

      00:40 tx/rx: 45334/15781 - 394 msgs/sec (2538 microsecs/roundtrip)

      00:42 tx/rx: 56629/15781 - 375 msgs/sec (2666 microsecs/roundtrip)

      00:44 tx/rx: 68025/15781 - 358 msgs/sec (2793 microsecs/roundtrip)

       

      second run:

      00:02 tx/rx: 6860/6475 - 3229 msgs/sec (309 microsecs/roundtrip)

      00:04 tx/rx: 14127/13664 - 3411 msgs/sec (293 microsecs/roundtrip)

      00:06 tx/rx: 21018/20612 - 3432 msgs/sec (291 microsecs/roundtrip)

      00:08 tx/rx: 27730/27383 - 3420 msgs/sec (292 microsecs/roundtrip)

      00:10 tx/rx: 35252/34676 - 3465 msgs/sec (288 microsecs/roundtrip)

      00:12 tx/rx: 42190/41686 - 3470 msgs/sec (288 microsecs/roundtrip)

      00:14 tx/rx: 48991/48469 - 3459 msgs/sec (289 microsecs/roundtrip)

      00:16 tx/rx: 56317/55919 - 3492 msgs/sec (286 microsecs/roundtrip)

       

      third run:

      00:02 tx/rx: 10365/903 - 450 msgs/sec (2222 microsecs/roundtrip)

      00:04 tx/rx: 20942/2206 - 550 msgs/sec (1818 microsecs/roundtrip)

      00:06 tx/rx: 31940/2945 - 490 msgs/sec (2040 microsecs/roundtrip)

      00:08 tx/rx: 43079/4380 - 547 msgs/sec (1828 microsecs/roundtrip)

      00:10 tx/rx: 54334/4640 - 463 msgs/sec (2159 microsecs/roundtrip)

      00:12 tx/rx: 65628/4640 - 386 msgs/sec (2590 microsecs/roundtrip)

      THabariReceiveThread: Synapse TCP/IP Socket error 10060: Connection timed out

      00:14 tx/rx: 76917/4640 - 331 msgs/sec (3021 microsecs/roundtrip)

      00:16 tx/rx: 88225/4640 - 289 msgs/sec (3460 microsecs/roundtrip)

       

      --

      Michael Justin

      habarisoft - Enterprise Messaging Software for Delphi

      http://www.habarisoft.com/

        • 1. Re: STOMP - alternating low/high transfer rates
          Clebert Suconic Master

          You should probably try the Branch from AS7.

           

          We have done a few changes on Stomp (especially on flow control)

          1 of 1 people found this helpful
          • 3. Re: STOMP - alternating low/high transfer rates
            Michael Justin Novice

            Here are results for HornetQ Server version 2.2.10.Final (HQ_2_2_10_FINAL_AS7, 122):

             

            1.)

            transfer speed to broker is much higher, but delivery to consumer is slow (so the broker will use up resources quickly)

             

            00:01 tx/rx: 37034/596 - 298 msgs/sec (3355 microsecs/roundtrip)

            00:03 tx/rx: 78983/1206 - 301 msgs/sec (3322 microsecs/roundtrip)

            00:05 tx/rx: 119359/2077 - 346 msgs/sec (2890 microsecs/roundtrip)

            00:07 tx/rx: 164203/2386 - 298 msgs/sec (3355 microsecs/roundtrip)

            00:09 tx/rx: 209750/2524 - 252 msgs/sec (3968 microsecs/roundtrip)

            00:11 tx/rx: 240705/2672 - 222 msgs/sec (4504 microsecs/roundtrip)

            00:14 tx/rx: 283903/2801 - 200 msgs/sec (5000 microsecs/roundtrip)

             

            10,000 to 20,000 messages per seconds is a great value (values are lower than possible as a Ubuntu virtual machine was running on the notebook, with Jenkins downloading and building HornetQ!)

             

            2.)

            repeated runs do not show significant changes in the send / receive speed

             

            Should I update to STOMP 1.1 or would this not make a big difference regarding transfer rate balancing?

             

            I will regularly try new builds, and post news here.

            • 4. Re: STOMP - alternating low/high transfer rates
              Clebert Suconic Master

              This will depend on how you ACK.. I'm making a few changes on confirmation and flow control. Maybe we will get things better...

               

              It would be nic if you could provide us the code, so we could change how to improve it.

              1 of 1 people found this helpful
              • 5. Re: STOMP - alternating low/high transfer rates
                Michael Justin Novice

                As a quick solution the producer now adds a short pause after every 20 messages.

                 

                Sleep(1 ms) after every 20 messages:

                 

                    00:02 tx/rx 25740/3705 12831/1846 msgs/sec (77/541 microsecs/msg)

                    00:04 tx/rx 53101/7405 13255/1848 msgs/sec (75/541 microsecs/msg)

                    00:06 tx/rx 79640/11288 13260/1879 msgs/sec (75/532 microsecs/msg)

                    00:08 tx/rx 104520/14562 13055/1818 msgs/sec (76/550 microsecs/msg)

                    00:10 tx/rx 130760/18829 13066/1881 msgs/sec (76/531 microsecs/msg)

                 

                 

                Sleep(5 ms) after every 20 messages:

                 

                    00:02 tx/rx 7640/3622 3812/1807 msgs/sec (262/553 microsecs/msg)

                    00:04 tx/rx 14660/10794 3661/2695 msgs/sec (273/371 microsecs/msg)

                    00:06 tx/rx 21480/18171 3577/3026 msgs/sec (279/330 microsecs/msg)

                    00:08 tx/rx 28140/25642 3515/3203 msgs/sec (284/312 microsecs/msg)

                    00:10 tx/rx 34980/32692 3496/3267 msgs/sec (286/306 microsecs/msg)

                 

                 

                And the values without throttling

                 

                    00:02 tx/rx 44065/494 21988/246 msgs/sec (45/4065 microsecs/msg)

                    00:04 tx/rx 90493/756 22595/188 msgs/sec (44/5319 microsecs/msg)

                    00:06 tx/rx 142982/907 23810/151 msgs/sec (41/6622 microsecs/msg)

                    00:08 tx/rx 192562/1144 24055/142 msgs/sec (41/7042 microsecs/msg)

                    00:10 tx/rx 237294/1395 23717/139 msgs/sec (42/7194 microsecs/msg)

                 

                The Delphi source code is quite high level (see below), would it help to show a STOMP frame log?

                 
                      while not CtrlC do
                      begin
                        for I := 0 to 19 do
                        begin
                          Msg := Session.CreateTextMessage('payload');
                          try
                            Producer.Send(Msg);
                          except
                            on E: Exception do
                            begin
                              Log('SendThread: ' + E.Message);
                            end;
                          end;
                          Inc(Sent);
                        end;
                        Sleep(3);
                      end;