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:[EMAIL PROTECTED]
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.
>
>
________________________________________________________________________
---
Daniel Kulp
[EMAIL PROTECTED]
http://www.dankulp.com/blog
________________________________________________________________________
In order to protect our email recipients, Betfair Group use SkyScan from
MessageLabs to scan all Incoming and Outgoing mail for viruses.
________________________________________________________________________
