On Jul 17, 2008, at 11:17 AM, David Soroko wrote:

Perhaps I should explain why I think this is an interesting question.

Imagine two frameworks: framework10 and framework100. During performance
testing it is observed that on a given hardware framwork10 supports up
to 10 requests per second (rps) with a "good enough" response time at
which point the CPU usage hits 100% and the system becomes unusable.
On the same hardware and executing the same logic framework100 supports
up to 100 rps. with a "good enough" response time at which point the
system become unusable.

This means that in production, a business will need 10 times more
hardware (nodes, CPU power, whatever) to support the same load with
framework10 then with framework100.

To give some perspective, in our tests, the servlet container (Tomcat)
uses about 15% and CXF about 80%, the rest is business logic.

Depends on the business logic. :-) If the business logic is doing all kinds of database lookups, transforms, etc..., that percentage would go up. If it's just:
 return "hello " + arg1;
the percentage is obviously very small.

Seriously, processing the XML is quite CPU intensive. The pull parsers (woodstox) are very fast at doing it, but it does still involve quite a bit of CPU processing. JAXB is also fairly CPU intensive as it involves a lot of reflection work to get/set fields, etc.... (again, sxc can help) Basically, getting all of that fast is hard, which is why users use toolkits like CXF or whatever. We can optimize it and benefit all our users.

In any case, as you dig in feel free to log jiras and attach patches. This is definitely a great way to get involved with CXF. We had people become committers doing many memory optimizations. Doing performance optimizations is another big help.


Dan







Now I wonder if this kind of breakdown is expected (given the services
the CXF provides) or is a misconfiguration/bug the needs to be fixed.

thanks

-- david



-----Original Message-----
From: David Soroko [mailto:[EMAIL PROTECTED]
Sent: 16 July 2008 10:45
To: users@cxf.apache.org
Subject: RE: A CXF 2.1 CPU consumption question

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.

________________________________________________________________________

________________________________________________________________________
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




Reply via email to