[rabbitmq-discuss] problem with increasing response times

[tgv amni]

We are new to rabbitMQ. We use rabbitmq 3.1.5 in our test environment. This
is installed on a red hat linux server (6.4), the same server where our
application is also running. The database (postgresql) is on a separate
server.
We are using rabbitMQ default configuration.
I ran a test where concurrent users post to a rest service (say R). This
service basically expects  two UUIDs (UUID_A and UUID_B), that identify two
database entities  A and B. Once the service is called with these two
values, it publishes to the default exchange.
There are two durable queues bound to this exchange. QueueA and QueueB. Two
services,  Service A and Service B, each listen on QueueA and QueueB
respectively.  There are no other consumers to these queues. Service A
picks up the message and validates  UUID_A exists in the database. Service
B validates UUID_B exists. If they are both valid, an entry is made to the
db, mapping these two values. So each valid post results in an entry in a
table in the db.

I find as the test progresses, response  time of this post increases.  A
lot of the time is being spent in  Unsafe.park (boolean,long)  in sun.misc
package.

Here is the call stack that shows classes where this Unsafe.park() is being
involved from. It appears to be called from spring framework’s
RabbitTemplate class.

Unsafe.park

 LockSupportparkNanos(Object,Long)

  * **AbstractQueuedSynchronizer$ConditionObject.awaitNanos(long)*

     ArrayBlockingQueue.poll(long, TimeUnit)

        RabbitTemplate$3.doInRabbit(Channel)

           RabbitTemplate$3.doInRabbit(Channel)

RabbitTemplate.execute(ChannelCallback)

  * **RabbitTemplate.doSendAndReceiveWithTemporary(String,String,Message)*

      RabbitTemplate.doSendAndReceive(String,String,Message)

         RabbitTemplate.convertSendAndReceive(String,String,Object,
MessagePostProcessor)


RabbitTemplate.convertSendAndReceive(String,Object)

…

           …

As the test progresses where the load increases from 50 users to 200 users
over a period of 20 mins, this response time increases from 50 ms to almost
2 seconds. 99% of the response time is spent in Unsafe.park (waiting).  At
the end of 20 mins, roughly 100,000 entries are made into the db.That is
roughly 83 Posts (i.e messages) per second. Each message contains a couple
of UUIDs and a couple of dates. There is no other activity on this server.
Why is there so mcuh time being spent in Unsafe.park() ? It looks like
there is a wait for some resource lock. How can we reduce this wait ?
Overall CPU is about 40-45% on this box (a 12 core server). 2/3rds of this
time is being spent in the rabbitMQ server.
Is there a plug-in to monitor cpu usage on the server? How can we determine
where time is being spent within the broker ?

Thanks,

tgv
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20130929/5d094484/attachment.htm>