You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by bwatrous <be...@jpmchase.com> on 2007/06/28 18:36:24 UTC

CPP client: high latency for large messages

Hi,
  I've just started experimenting with the performance of the ActiveMQ CPP
client.  I'm using Active MQ 4.0.2 and ActiveMQ CPP 2.0.1 on Redhat
Enterprise 3 with gcc 3.2.3.  I'm comparing a simple benchmark application
written in C++ with a similar one written in Java.
  I'm seeing reasonable performance (sub-millisecond latency) when sending
messages < 802 bytes, but at exactly 802 bytes the latency increases by 2
orders of magnitude.  This is independent of whether I enable persistence,
async_send, change the acknowledgement mode for consumers, etc.  Again, this
doesn't happen in a similar Java client.  My guess is that there is a bug in
how the C++ client fragments larger messages, but it may well be a problem
with how I'm using it.
  I've stripped my code down to a simple example that's very close to the
example code.  Can anyone tell me what I'm doing wrong, or if this is a bug
in the ActiveMQ Cpp client?
  Here's the output from 2 runs right around the breaking point:

RUN 1:
~/test/cppProducer $ ./benchmark -msgs 100 -size 802
=====================================================
Num Messages : 100
Message Length: 802 bytes
AMQ Broker URI:
tcp://localhost:61616?wireFormat=openwire&transport.useAsyncSend=true

-----------------------------------------------------
..................................................
..................................................
Sent 100 messages of size: 802
Avg Send Time = 0.0402068
Total: 4.02068
=====================================================

RUN 2:
~/test/cppProducer $ ./benchmark -msgs 100 -size 801
=====================================================
Num Messages : 100
Message Length: 801 bytes
AMQ Broker URI:
tcp://localhost:61616?wireFormat=openwire&transport.useAsyncSend=true
-----------------------------------------------------

..................................................
..................................................
Sent 100 messages of size: 801
Avg Send Time = 0.000161011
Total: 0.0161011
=====================================================
~/test/cppProducer $ 


Here's the sample code:
/*--- File: main.cpp --*/
#include <activemq/core/ActiveMQConnectionFactory.h>
#include <activemq/concurrent/Thread.h>
#include <activemq/concurrent/Thread.h>
#include <activemq/util/Integer.h>
#include <activemq/util/Config.h>
#include <cms/TextMessage.h>
#include <cms/BytesMessage.h>
#include <cms/MapMessage.h>
#include <cms/ExceptionListener.h>
#include <cms/MessageListener.h>
#include <stdlib.h>
#include <algorithm>
#include <numeric>
#include <iomanip>
#include <iostream>
#include <sys/time.h>
#include <time.h>
#include <unistd.h>

using namespace activemq::core;
using namespace activemq::concurrent;
using namespace cms;
using namespace std;

int main(int argc, char* argv[] ) {

   string baseBrokerURI = "localhost:61616";
   unsigned long numMessages = 1000;
   unsigned int messageLength = 100;
   std::cout << "=====================================================\n";

   // Parse the command line (if any)
   int nextArg = 1;
   while ( nextArg < argc ) {
      string nextToken = argv[ nextArg++ ]; 
      if ( nextToken == "-msgs" ) {
         numMessages = atoi( argv[ nextArg++ ]);
         std::cout << "Num Messages : " << numMessages << std::endl;        
      } else if ( nextToken == "-size" ) {
         messageLength = atoi( argv[ nextArg++ ]);
         std::cout << "Message Length: " << messageLength << " bytes" <<
std::endl;
      } else if ( nextToken == "-uri" ) {
         baseBrokerURI = argv[ nextArg++ ];
         std::cout << "Broker URI : " << baseBrokerURI << std::endl;
      } else {
	std::cout << "Usage:\nbenchmark [-h][-msgs count(default: 1000)][-size
messageLength(default:100)][-uri host:port]" << std::endl;
	return 0;
      };
   };
   std::string brokerURI = string( "tcp://" ) + baseBrokerURI;
   brokerURI += "?wireFormat=openwire&transport.useAsyncSend=true";
   std::cout << "AMQ Broker URI: " << brokerURI << std::endl;
   std::cout << "-----------------------------------------------------" <<
std::endl;

   // Create a ConnectionFactory
   ActiveMQConnectionFactory* ConnectionFactory =
     new ActiveMQConnectionFactory( brokerURI );

   // Create a Connection
   cms::Connection* myConnection =
      ConnectionFactory->createConnection();
   myConnection->start();
   string myClientId = myConnection->getClientID();

   // Create a Session
   cms::Session* mySession =
      myConnection->createSession( cms::Session::AUTO_ACKNOWLEDGE );

   // Create a Destination
   cms::Destination* myDestination =
      mySession->createQueue( "SimpleCppTestQueue" );   

   // Create a Producer
   cms::MessageProducer* myProducer =
      mySession->createProducer( myDestination );
   myProducer->setDeliveryMode( DeliveryMode::PERSISTENT );
   
   // Create a Message to send
   string text;
   for ( unsigned int nextChar = 0; nextChar < messageLength; ++nextChar ) {
      text += 'A' + ( nextChar % 26 );
   }
   TextMessage* message = mySession->createTextMessage( text );

   // Start timer
   struct timeval time; 
   gettimeofday(&time,0);
   double startTime = (double)time.tv_sec + (double)time.tv_usec / 1000000;
      
   // Send the messages
   for( unsigned int i = 0; i < numMessages; ++i ) {
     std::cout << ((i%50)?".":"\n.") << std::flush;
     myProducer->send( message );
   }

   // Stop timer
   gettimeofday(&time,0);
   double stopTime = (double)time.tv_sec + (double)time.tv_usec / 1000000;
   double elapsed = stopTime - startTime;
   double avgSendTime = elapsed / numMessages;
   std::cout << "\nSent " << numMessages << " messages of size: " <<
messageLength << std::endl;
   std::cout << "Avg Send Time = " << avgSendTime << std::endl;
   std::cout << "Total: " << elapsed << std::endl;
   std::cout << "=====================================================\n";
}


Build Command:
g++  -g -pthread -I~/activemq/activemq-cpp-2.0.1-src/src/main  -c -o main.o
main.cpp
g++ -o benchmark main.o -pthread
-L~/activemq/activemq-cpp-2.0.1-src/src/main -lactivemq-cpp -luuid


-- 
View this message in context: http://www.nabble.com/CPP-client%3A-high-latency-for-large-messages-tf3995387s2354.html#a11346562
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: CPP client: high latency for large messages

Posted by davidmc <ar...@gmail.com>.
Hi again Ben,

Actually, 802 bytes is not a big message in this problem :) It's rather
small.
I did a rather extensive test in this subject... sadly I am not a TCP
implementation expert, so I cannot give a good explanation. But my results
were more or less like this:
-big messages (more than 8KB-16KB depending on the situations -> no 40 ms
latency, probably because buffer is full with 1 message and TCP decides to
send it as a packet right away)
-small messages (less than 8KB-16KB) -> 40 ms latency.
-very small messages (some hundres bytes) -> no 40 ms latency. Why? I have
no idea.

Also, I'm happy that my advice helped you :) Just a little warning... even
if the fix to the connection URL dropped your AVERAGE latency, you still may
get some 40ms latencies here and there because the broker's sockets don't
have TCP_NODELAY enabled.
So, if all you care is the average, then you should not worry anymore. If
you don't want to have any 40 ms latencies at all, then I recommend you to
slightly modify your test program to check that you don't get any latencies
in the 38-41 ms range. Also, if you do get some 40 ms latencies, think that
during those 40ms no other messages can be sent... so actually you can have
a situation similar to this:
during 1 second, 1000 messages are sent, but 20 of them have 40ms latencies.
20*40 = 800 ms, so 80% of the time is lost because of this. Yet the average
latency is 800 / 1000 = 0.8 ms (supposing the other 980 messages have
negligeable latency), kind of very low, and you may not notice that
something wrong is happening.

Well, anyway... most probably you don't need to worry any more, so I'm happy
that you got your problem solved.

David


bwatrous wrote:
> 
> Hi David,
>    Thank you for the advice.  I didn't think the tcpNoDelay would have an
> effect since I was looking at relatively large messages :)
>    Simply changing the connection URL solved the immediate problem, send
> latency dropped right down into the microseconds as expected.  So far I
> haven't had to make the suggested changes to the broker.
> 
> Ben
> 
> 
> davidmc wrote:
>> 
>> Hi there bwatrous,
>> 
>> Your average sent time for the problematic RUN 1 (40ms) indicates that
>> your problem is most probably caused by the bad Nagle's algorithm /
>> Delayed ACK timeout interaction. This timeout is 40ms in Linux and 200ms
>> in Windows / other systems.
>> 
>> In short, the solution is to enable TCP_NODELAY flag on all your sockets.
>> -This is possible in the ActiveMQ CPP client since version 2.0.1. You
>> should append tcpNoDelay=true to the connection URL.
>> -On the broker's side, you should enable the TCP_NODELAY flag in the
>> broker's sockets. For this, following the documentation, you should
>> append 'wireFormat.tcpNoDelayEnabled=true' to your connector's URI.
>> In fact, this doesn't work and it is silently ignored. I discovered that
>> 'socket.tcpNoDelay=true' works if you append it to an ActiveMQ Java
>> CLIENT's connection URI; but it still doesn't work for a BROKER's
>> connector URI.
>> So, the only solution is to go to the broker's source code
>> (org.apache.activemq.transport.tcp.TcpTransport.initialiseSocket method)
>> and add the following line of Java code:
>> --->          sock.setTcpNoDelay(true);         <---
>> at the end of the method, so that all broker's sockets are created with
>> TCP_NODELAY=true by default.
>> 
>> The parsing of options in a broker's activemq.xml connector URI is broken
>> right now, and it sadly doesn't seem to be a priority that this is fixed
>> for next releases.
>> So, I wonder how many folks encounter this '40 ms' problem, and when they
>> finally guess that the solution is the TCP_NODELAY flag (not so easy),
>> they try it and think it was not the right solution because
>> 'wireFormat.tcpNoDelayEnabled=true' or 'tcpNoDelay=true' or
>> 'socket.tcpNoDelay=true' get all silently ignored (no error message, but
>> no effect on the sockets). Probably lots of frustration and lost hours...
>> :(
>> 
>> Related messages and JIRA's:
>> https://issues.apache.org/activemq/browse/AMQ-1156
>> https://issues.apache.org/activemq/browse/AMQ-1137
>> http://issues.apache.org/activemq/browse/AMQ-1233
>> http://www.nabble.com/AMQCPP-Openwire-much-slower-than-Stomp--tf3599986s2354.html#a10055544
>> 
> 
> 

-- 
View this message in context: http://www.nabble.com/CPP-client%3A-high-latency-for-large-messages-tf3995387s2354.html#a11387205
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: CPP client: high latency for large messages

Posted by bwatrous <be...@jpmchase.com>.
Hi David,
   Thank you for the advice.  I didn't think the tcpNoDelay would have an
effect since I was looking at relatively large messages :)
   Simply changing the connection URL solved the immediate problem, send
latency dropped right down into the microseconds as expected.  So far I
haven't had to make the suggested changes to the broker.

Ben


davidmc wrote:
> 
> Hi there bwatrous,
> 
> Your average sent time for the problematic RUN 1 (40ms) indicates that
> your problem is most probably caused by the bad Nagle's algorithm /
> Delayed ACK timeout interaction. This timeout is 40ms in Linux and 200ms
> in Windows / other systems.
> 
> In short, the solution is to enable TCP_NODELAY flag on all your sockets.
> -This is possible in the ActiveMQ CPP client since version 2.0.1. You
> should append tcpNoDelay=true to the connection URL.
> -On the broker's side, you should enable the TCP_NODELAY flag in the
> broker's sockets. For this, following the documentation, you should append
> 'wireFormat.tcpNoDelayEnabled=true' to your connector's URI.
> In fact, this doesn't work and it is silently ignored. I discovered that
> 'socket.tcpNoDelay=true' works if you append it to an ActiveMQ Java
> CLIENT's connection URI; but it still doesn't work for a BROKER's
> connector URI.
> So, the only solution is to go to the broker's source code
> (org.apache.activemq.transport.tcp.TcpTransport.initialiseSocket method)
> and add the following line of Java code:
> --->          sock.setTcpNoDelay(true);         <---
> at the end of the method, so that all broker's sockets are created with
> TCP_NODELAY=true by default.
> 
> The parsing of options in a broker's activemq.xml connector URI is broken
> right now, and it sadly doesn't seem to be a priority that this is fixed
> for next releases.
> So, I wonder how many folks encounter this '40 ms' problem, and when they
> finally guess that the solution is the TCP_NODELAY flag (not so easy),
> they try it and think it was not the right solution because
> 'wireFormat.tcpNoDelayEnabled=true' or 'tcpNoDelay=true' or
> 'socket.tcpNoDelay=true' get all silently ignored (no error message, but
> no effect on the sockets). Probably lots of frustration and lost hours...
> :(
> 
> Related messages and JIRA's:
> https://issues.apache.org/activemq/browse/AMQ-1156
> https://issues.apache.org/activemq/browse/AMQ-1137
> http://issues.apache.org/activemq/browse/AMQ-1233
> http://www.nabble.com/AMQCPP-Openwire-much-slower-than-Stomp--tf3599986s2354.html#a10055544
> 

-- 
View this message in context: http://www.nabble.com/CPP-client%3A-high-latency-for-large-messages-tf3995387s2354.html#a11361530
Sent from the ActiveMQ - User mailing list archive at Nabble.com.


Re: CPP client: high latency for large messages

Posted by davidmc <ar...@gmail.com>.
Hi there bwatrous,

Your average sent time for the problematic RUN 1 (40ms) indicates that your
problem is most probably caused by the bad Nagle's algorithm / Delayed ACK
timeout interaction. This timeout is 40ms in Linux and 200ms in Windows /
other systems.

In short, the solution is to enable TCP_NODELAY flag on all your sockets.
-This is possible in the ActiveMQ CPP client since version 2.0.1. You should
append tcpNoDelay=true to the connection URL.
-On the broker's side, you should enable the TCP_NODELAY flag in the
broker's sockets. For this, following the documentation, you should append
'wireFormat.tcpNoDelayEnabled=true' to your connector's URI.
In fact, this doesn't work and it is silently ignored. I discovered that
'socket.tcpNoDelay=true' works if you append it to an ActiveMQ Java CLIENT's
connection URI; but it still doesn't work for a BROKER's connector URI.
So, the only solution is to go to the broker's source code
(org.apache.activemq.transport.tcp.TcpTransport.initialiseSocket method) and
add the following line of Java code:
--->          sock.setTcpNoDelay(true);         <---
at the end of the method, so that all broker's sockets are created with
TCP_NODELAY=true by default.

The parsing of options in a broker's activemq.xml connector URI is broken
right now, and it sadly doesn't seem to be a priority that this is fixed for
next releases.
So, I wonder how many folks encounter this '40 ms' problem, and when they
finally guess that the solution is the TCP_NODELAY flag (not so easy), they
try it and think it was not the right solution because
'wireFormat.tcpNoDelayEnabled=true' or 'tcpNoDelay=true' or
'socket.tcpNoDelay=true' get all silently ignored (no error message, but no
effect on the sockets). Probably lots of frustration and lost hours... :(

Related messages and JIRA's:
https://issues.apache.org/activemq/browse/AMQ-1156
https://issues.apache.org/activemq/browse/AMQ-1137
http://issues.apache.org/activemq/browse/AMQ-1233
http://www.nabble.com/AMQCPP-Openwire-much-slower-than-Stomp--tf3599986s2354.html#a10055544
-- 
View this message in context: http://www.nabble.com/CPP-client%3A-high-latency-for-large-messages-tf3995387s2354.html#a11355089
Sent from the ActiveMQ - User mailing list archive at Nabble.com.