[rabbitmq-discuss] Java client - 91% time spent in reading the socket?

[Tim Robertson]

Hi all,

I am trying to optimize our processes, and I attached a profiler to the
Java client reading from Rabbit.
I am seeing the profiler report 91% of the time spent reading the socket,
which I find somewhat surprising (the consumer is doing quite some
computation and then writing to HBase so I was expecting my own part to be
the slowest).

Our messages are JSON encoded and I have a sample message [1] which is
about 3kb when saved as a text file.

The profile thread timing is showing the following:
com.rabbitmq.client.impl.AMQConnection$MainLoop.run()
 - com.rabbitmq.client.impl.SocketFrameHandler.readFrame()
  - com.rabbitmq.client.impl.Frame.readFrom(DataInputStream) 167394
   -  java.io.DataInputStream.readUnsignedByte() 166968
    -   java.io.BufferedInputStream.read() 166968
     -    java.io.BufferedInputStream.fill() 166968
      -     java.net.SocketInputStream.read(byte[], int, int) 166968
       -      [Wall Time]
 java.net.SocketInputStream.socketRead0(FileDescriptor, byte[], int, int,
int)         91%

I'm seeing only around 400 messages per second (lots of resources - 24
cores, 40GB memory, fast network) and using v3.0.4.  We're using easyrabbit
libraries, but basically it boils down to a channel.basicConsume(...) with
explicit acking.

Does this look suspicious to anyone?  Can anyone shed any light on how one
might improve this?

Thanks for any insights,
Tim
- a rabbit newbie


[1]
https://dl.dropboxusercontent.com/u/608155/transient/sampleRabbitMessage.json
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rabbitmq.com/pipermail/rabbitmq-discuss/attachments/20130801/bb088cb4/attachment.htm>