My application uses Google Protocol Buffer with Apache MINA. There are clients who connect to the MINA Connector, send request to the server and then wait for the response from the server. The flow of control is as follows:1. Client sends request2. Request received at MINA filter (<Class> extends CumulativeProtocolDecoder)3. doDecode() method is called4. A request object (generated from *.proto file) is created using the <RequestObject>.parseFrom(bytes)5. The request is passed on to the IOHandler (<Class> extends IoHandlerAdapter)6. messageReceived() method is called7. In this method, the request object (from #7) is processed to create the list of requests which has been sent by the client.8. At this point, we have noticed that the time taken to process the request object (#7) is gradually degrading with time. From a initial period of around 2 ms, the time period is going up to 200 ms in just 8 days of continuous usage. And this value gradually increases with time.9. The request list is processed in the application10. The response object is created11. The response is sent to the client.Any suggestion would be highly appreciated.
What makes you think it's protobuf's problem?
On Friday, January 11, 2013 2:50:54 PM UTC+8, debo...@2pirad.com wrote:
My application uses Google Protocol Buffer with Apache MINA. There are clients who connect to the MINA Connector, send request to the server and then wait for the response from the server. The flow of control is as follows:1. Client sends request2. Request received at MINA filter (<Class> extends CumulativeProtocolDecoder)3. doDecode() method is called4. A request object (generated from *.proto file) is created using the <RequestObject>.parseFrom(bytes)5. The request is passed on to the IOHandler (<Class> extends IoHandlerAdapter)6. messageReceived() method is called
7. In this method, the request object (from #6) is processed to create the list of requests which has been sent by the client.
Because, to process the request object (in #7), the methods which are present in the google protobuf generated file are called. The protobuf request object contains multiple requests, and the time taken to extract these (requests) is gradually increasing with time.
My application uses Google Protocol Buffer with Apache MINA. There are clients who connect to the MINA Connector, send request to the server and then wait for the response from the server. The flow of control is as follows:1. Client sends request2. Request received at MINA filter (<Class> extends CumulativeProtocolDecoder)3. doDecode() method is called4. A request object (generated from *.proto file) is created using the <RequestObject>.parseFrom(bytes)5. The request is passed on to the IOHandler (<Class> extends IoHandlerAdapter)6. messageReceived() method is called
7. In this method, the request object (from #7) is processed to create the list of requests which has been sent by the client.
if i undestand correctly, You have a looong-run application.
- at start You have 2 ms cycle request-response
- after a week You have 200 ms cycle
- Your app is correct and only place where problem may lay is protobuf?
can You do the following?
-- run 'latencytop' at start and after a week?
-- run 'oprofile' at start and after a week?
-- may be its reasonable to writeout times from crititical points of Ypur app? smth like: before req? after req? before response - after response
from my [very limited] exp a such problems traditionally becomes from unintendend sources -- memory allocator, log sub-system, database, swap, etc...
Hi Xiao Feng, please find below the relevant sections of my applications code:This is the point where Apache MINA receives the request from the client. The MultiRequest is a generated class from the protobuf compiler. The .proto file and the java source code is attached for your reference.public class ProtocolBufferDecoder extends CumulativeProtocolDecoder {.....@Overrideprotected boolean doDecode(IoSession session, IoBuffer in, ProtocolDecoderOutput out)throws Exception {if (!in.prefixedDataAvailable(4)) {return false;}double randomId = Math.random();session.setAttribute("requestId", randomId);// read the bytesin.rewind();byte[] bytes = new byte[in.getInt()];in.get(bytes);// parse the bytesLOGGER.trace("creating request object from bytes for request id: {}", randomId);MultiRequest request = MultiRequest.parseFrom(bytes);
LOGGER.debug("MultiRequest[{}] created successfully for request id: {}",randomId);// send the requestout.write(request);LOGGER.trace("sending request to io handler for request id: {}", randomId);return true;}}
After the Multirequest object is created, it is passed on to the MINA IO Handler in the following section:public class SocketIoHandler extends IoHandlerAdapter {.........public void messageReceived(IoSession session, Object message)throws Exception {// decode requestsLOGGER.trace("starting to decode request with id: {}",session.getAttribute("requestId"));List<Request> requestList = requestCodec.decodeAll(message);LOGGER.trace("finished decoding request with id: {}", session.getAttribute("requestId"));.........}.........}The SimpleProtocolBufferDecoder (attached) decodes the MultiRequest and returns a list of request objects.Thanks & Best Regards,
Debopam
Cell: +919830410041
------------------------------------------------------------------
-|-
--o-0-(.)-0-o--
visit us at www.2pirad.comOn Fri, Jan 11, 2013 at 3:06 PM, Feng Xiao <xiao...@google.com> wrote:Can you show us how the decoding code looks like? I.e., the range of code that you found is slowing over time.
____________________________________ Visit us at http://www.2pirad.com