Hi Xiao Feng,
The line which is getting slower with time is highlighted in yellow, below. On Friday, January 11, 2013 4:31:46 PM UTC+5:30, Feng Xiao wrote: > > > [adding back the group] > > On Fri, Jan 11, 2013 at 5:53 PM, Debopam Ghoshal > <[email protected]<javascript:> > > wrote: > >> 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 { >> ..... >> >> @Override >> protected 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 bytes >> in.rewind(); >> byte[] bytes = new byte[in.getInt()]; >> in.get(bytes); >> >> // parse the bytes >> LOGGER.trace("creating request object from bytes for request id: >> {}", randomId); >> *MultiRequest request = MultiRequest.parseFrom(bytes);* >> > Is it this line of code that you found gets slower over time? I see no > reason why it should behave like that unless "bytes" is getting larger. > > >> LOGGER.debug("MultiRequest[{}] created successfully for request >> id: {}", >> randomId); >> >> // send the request >> out.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 requests >> LOGGER.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.com >> >> >> On Fri, Jan 11, 2013 at 3:06 PM, Feng Xiao <[email protected]<javascript:> >> > wrote: >> >>> Can you show us how the decoding code looks like? I.e., the range of >>> code that you found is slowing over time. >>> >>> >>> On Friday, January 11, 2013 4:45:40 PM UTC+8, [email protected] wrote: >>>> >>>> Thanks for your suggestions. Please find my response below: >>>> >>>> >>>> On Friday, January 11, 2013 1:16:19 PM UTC+5:30, Дмитрий Дьяченко wrote: >>>>> >>>>> if i undestand correctly, You have a looong-run application. >>>>> >>>> Yes, you are right, my application is a really looooong running one. It >>>> is expected to run 24 x 7 x 365. >>>> >>>> >>>>> - at start You have 2 ms cycle request-response >>>>> >>>> The actual request response cycle is a bit more than 2 ms, because >>>> after the request is recieved by the application (#9 in my list), it does >>>> a >>>> few things, which may take longer. But, the time taken to decode the >>>> protobuf request is 2 ms at start. >>>> >>>> >>>>> - after a week You have 200 ms cycle >>>>> >>>> Right, the time taken to decode gradually increases and becomes 200 ms. >>>> If left running for longer, it even reached 1 sec in 15 days time. >>>> >>>> >>>>> - Your app is correct and only place where problem may lay is protobuf? >>>>> >>>> From the logs which are there in my application, I have seen that only >>>> the time taken to decode is gradually increasing. I have also done some >>>> memory and thread profiling of my application, but did not find any >>>> irregularities (like increase in memory/threads) >>>> >>>> >>>>> >>>>> can You do the following? >>>>> -- run 'latencytop' at start and after a week? >>>>> -- run 'oprofile' at start and after a week? >>>>> >>>> My application is running on IBM AIX server (using IBM JVM). Are the >>>> above tools available for AIX? >>>> >>>> >>>>> -- may be its reasonable to writeout times from crititical points of >>>>> Ypur app? smth like: before req? after req? before response - after >>>>> response >>>>> >>>> I have logs specific for this purpose which are there at the start and >>>> end of these points. Like, before decode and after decode, etc. From these >>>> logs I found out the point which was gradually slowing down. >>>> >>>> >>>>> from my [very limited] exp a such problems traditionally becomes from >>>>> unintendend sources -- memory allocator, log sub-system, database, swap, >>>>> etc... >>>>> >>>> The only other component involved over here (other than the application >>>> and JMV) is the network. But, I don't think network is the issue because >>>> the decoding is done after the request object is fully received from the >>>> client. Apache MINA is responsible for getting the request from the client. >>>> >>>> >>>>> >>>>> Thanks, >>>>> Dmitry >>>>> >>>>> пятница, 11 января 2013 г., 10:50:54 UTC+4 пользователь >>>>> [email protected] написал: >>>>>> >>>>>> 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 request >>>>>> 2. Request received at MINA filter (<Class> extends ** >>>>>> CumulativeProtocolDecoder) >>>>>> 3. doDecode() method is called >>>>>> 4. 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. >>>>>> * 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 >>>>>> application >>>>>> 10. The response object is created >>>>>> 11. The response is sent to the client. >>>>>> >>>>>> Any suggestion would be highly appreciated. >>>>>> >>>>> >> ____________________________________ >> Visit us at http://www.2pirad.com >> >> > -- You received this message because you are subscribed to the Google Groups "Protocol Buffers" group. To view this discussion on the web visit https://groups.google.com/d/msg/protobuf/-/Ev5MhXqi_FgJ. To post to this group, send email to [email protected]. To unsubscribe from this group, send email to [email protected]. For more options, visit this group at http://groups.google.com/group/protobuf?hl=en.
