cxf-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Glen Mazza <glen.ma...@gmail.com>
Subject Re: A CXF 2.1 CPU consumption question
Date Thu, 17 Jul 2008 14:16:31 GMT

David, the very same developers are on both lists.  Best to follow up on the
User's list to keep the archives clean for future searching.

Glen


David Soroko wrote:
> 
> Hello all
> 
>  
> 
> I apologise for cross posting, but I was not getting much traction in
> the users-list and I do think that my question is worth asking and
> answering. Here is what I have so far:
> 
>  
> 
>  
> 
>  
> 
>  
> 
>  
> 
>  
> 
> Hello Daniel
> 
>  
> 
> I had another profiling session and this time saved the snapshot so we
> can have a fixed point of reference. I am using JProfiler with CPU
> measurement set to "Elapsed time", which according to the documentation
> should ignore time spent while waiting or blocking.
> 
>  
> 
> This time I have:
> 
>  
> 
> 74.1% PhaseInterceptorChain.doIntercept()
> 
>       30.5% OutgoingChainInterceptor.handleMessage
> 
>       21.3% ReadHeadersInterceptor.handleMessage
> 
>       7.3%  DocLiteralInInterceptor.handleMessage
> 
>       5.3%  ServiceInvokerInterceptor.handleMessage
> 
>  
> 
> Regarding ReadHeadersInterceptor.handleMessage. See image at:
> http://drop.io/pul3us5/asset/readheadersinterceptor
> 
>  
> 
> (The stack trace was re-rooted for display purposes to and that is why
> it is at 100%) 
> 
>  
> 
> It seems that most of the time is spent in xerces and wstx but what is
> it they do?
> 
>  
> 
>  
> 
> Regarding DocLiteralInInterceptor.handleMessage. See image at:
> http://drop.io/pul3us5/asset/docliteralininterceptor
> 
>  
> 
> Most work seems to be JAXB related.
> 
>  
> 
>  
> 
>  
> 
> Regarding ServiceInvokerInterceptor.handleMessage. Here the actual
> business logic is invoked. This reflective invocation takes up 3% of the
> total of ServiceInvokerInterceptor.handleMessage. Not sure what the rest
> is. Snapshot image is here:
> 
> http://drop.io/pul3us5/asset/serviceinvokerinterceptor
> 
>  
> 
>  
> 
> Regarding OutgoingChainInterceptor.handleMessage. An image is here:
> http://drop.io/pul3us5/asset/outgoingchaininterceptor
> 
>  
> 
> Would you say that 30% of the CPU is about the right slice size of the
> cake for CXF to take?
> 
>  
> 
>  
> 
> Thanks
> 
>  
> 
> -- david
> 
>  
> 
>  
> 
>  
> 
> -----Original Message-----
> 
> From: Daniel Kulp [mailto:dkulp@apache.org]
> 
> Sent: 15 July 2008 23:16
> 
> To: users@cxf.apache.org
> 
> Subject: Re: A CXF 2.1 CPU consumption question
> 
>  
> 
>  
> 
>  
> 
>  
> 
> On Jul 11, 2008, at 10:18 AM, David Soroko wrote:
> 
>  
> 
>> 
> 
>> 
> 
>> Hi all
> 
>> 
> 
>> We are now in profiling stages of some CXF 2.1 based web services. In
> 
>> all our services we observe that most of the CPU time is not  
> 
>> consumed by
> 
>> the service logic itself but by CXF. I attach a picture (worth 1000
> 
>> words) of a JProfiler snapshot. In the snapshot we see the
> 
>> PhaseInterceptorChain.doIntercept() taking 78.4% of the CPU which is
> 
>> fine as this includes the eventual service logic execution. What  
> 
>> happens
> 
>> next is a bit strange, here is the ASCII art rendering:
> 
>> 
> 
>> 78.4% PhaseInterceptorChain.doIntercept()
> 
>>      26.4% OutgoingChainInterceptor.handleMessage
> 
>  
> 
> This makes complete sense.   The OutgoingChainInterceptor sets up the  
> 
> outgoing chain and invokes it.   Thus, this number would include ALL  
> 
> of the work required to send the response including the JAXB  
> 
> marshalling, flushing the streams, etc....
> 
>  
> 
>> 
> 
>>      20.0% ServiceInvokerInterceptor.handleMessage
> 
>>      16.9% ReadHeadersInterceptor.handleMessage
> 
>> 
> 
>> 
> 
>> The call to ServiceInvokerInterceptor.handleMessage() ends up calling
> 
>> the actual service logic which takes about 5% of the CPU time so, the
> 
>> extra 15% penalty seems to excessive,
> 
>  
> 
> That's really not good.   Any chance you can dig into that one a bit  
> 
> furthur?
> 
>  
> 
>  
> 
>> what's even more worrying are the
> 
>> other two handleMessage calls (OutgoingChainInterceptor and
> 
>> ReadHeadersInterceptor) that gobble up together more then 40% of the
> 
>> CPU.
> 
>  
> 
> ReadHeadersInteceptor is the first interceptor that actual reads stuff  
> 
> off the wire.   Question: is it actually measuring CPU usage or just a  
> 
> "nanosecond count" or something. (raw time)   Normally, this is where  
> 
> it would pause waiting for the message to come off the network.   
> 
> Everytime I see a large number hear, it's not really using the CPU,  
> 
> it's actually down in the ServletInputStream waiting for data from the  
> 
> socket.
> 
>  
> 
>  
> 
> Dan
> 
>  
> 
>  
> 
>> Note that we have no custom interceptors defined, our configuration
> 
>> looks like this:
> 
>> 
> 
>> 
> 
>> <import resource="classpath:META-INF/cxf/cxf.xml"/>
> 
>> <import resource="classpath:META-INF/cxf/cxf-servlet.xml"/>
> 
>> <import resource="classpath:META-INF/cxf/cxf-extension-soap.xml"/>
> 
>> 
> 
>> <bean id="cxf" class="org.apache.cxf.bus.CXFBusImpl">
> 
>> 
> 
>> <jaxws:endpoint id="SomeServiceEndpoint"
> 
>>                    address="/SomeService"
> 
>>                    implementor="#someService"
> 
>> 
> 
>> implementorClass 
> 
>> ="com.betfair.services.someservice.SomeServiceServiceImp
> 
>> l">
> 
>> 
> 
>> 
> 
>> 
> 
>> Is this behaviour expected in a properly configured system?
> 
>> 
> 
>> Thanks
> 
>> 
> 
>> -- david
> 
>> 
> 
>> 
> 
>  
> 
>  
> 
>  
> 
>  
> 
> 
> ________________________________________________________________________
> In order to protect our email recipients, Betfair Group use SkyScan from 
> MessageLabs to scan all Incoming and Outgoing mail for viruses.
> 
> ________________________________________________________________________
> 

-- 
View this message in context: http://www.nabble.com/A-CXF-2.1--CPU-consumption-question-tp18509340p18509468.html
Sent from the cxf-dev mailing list archive at Nabble.com.


Mime
View raw message