-
1. Re: JAX-WS handler creates high CPU load
ctomc Sep 15, 2014 1:50 PM (in response to markusdlugi)Any chance you can produce thread dump when you get 100% cpu load, so we can see where the cpu is spending time
-
2. Re: Re: JAX-WS handler creates high CPU load
markusdlugi Sep 16, 2014 7:35 AM (in response to ctomc)I have attached the full output of jstack to the original post. I also used top to get the threads with the most CPU demand, and in 90% of cases, the top thread was in one of the following two states:
"Thread-771" daemon prio=10 tid=0x00007f496c462800 nid=0x7cd9 runnable [0x00007f47a5352000]
java.lang.Thread.State: RUNNABLE
at org.apache.cxf.phase.PhaseInterceptorChain.insertInterceptor(PhaseInterceptorChain.java:494)
at org.apache.cxf.phase.PhaseInterceptorChain.add(PhaseInterceptorChain.java:208)
at org.apache.cxf.phase.PhaseInterceptorChain.add(PhaseInterceptorChain.java:185)
at org.apache.cxf.phase.PhaseInterceptorChain.add(PhaseInterceptorChain.java:176)
at org.apache.cxf.phase.PhaseChainCache.getChain(PhaseChainCache.java:93)
at org.apache.cxf.phase.PhaseChainCache.get(PhaseChainCache.java:77)
at org.apache.cxf.endpoint.ClientImpl.onMessage(ClientImpl.java:744)
at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1694)
at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1530)
at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1438)
at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:659)
at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262)
- locked <0x000000069573afc8> (a org.apache.cxf.phase.PhaseInterceptorChain)
at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:463)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:366)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:319)
at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:134)
at com.sun.proxy.$Proxy61.test(Unknown Source)
at org.test.client.TestClient.run(TestClient.java:32)
"Thread-761" daemon prio=10 tid=0x00007f496c2b3000 nid=0x7ccf waiting for monitor entry [0x00007f47a5d5c000]
java.lang.Thread.State: BLOCKED (on object monitor)
at sun.net.www.http.KeepAliveCache.put(KeepAliveCache.java:80)
- waiting to lock <0x0000000680dc6388> (a sun.net.www.http.KeepAliveCache)
at sun.net.www.http.HttpClient.putInKeepAliveCache(HttpClient.java:353)
- locked <0x0000000692ca8830> (a sun.net.www.http.HttpClient)
at sun.net.www.http.HttpClient.finished(HttpClient.java:341)
at sun.net.www.http.KeepAliveStream.close(KeepAliveStream.java:100)
at sun.net.www.MeteredStream.justRead(MeteredStream.java:93)
at sun.net.www.MeteredStream.read(MeteredStream.java:135)
- locked <0x00000007882ca8a8> (a sun.net.www.http.KeepAliveStream)
at java.io.FilterInputStream.read(FilterInputStream.java:133)
at sun.net.www.protocol.http.HttpURLConnection$HttpInputStream.read(HttpURLConnection.java:3052)
at com.ctc.wstx.io.BaseReader.readBytes(BaseReader.java:155)
at com.ctc.wstx.io.UTF8Reader.loadMore(UTF8Reader.java:368)
at com.ctc.wstx.io.UTF8Reader.read(UTF8Reader.java:111)
at com.ctc.wstx.io.ReaderBootstrapper.initialLoad(ReaderBootstrapper.java:250)
at com.ctc.wstx.io.ReaderBootstrapper.bootstrapInput(ReaderBootstrapper.java:133)
at com.ctc.wstx.stax.WstxInputFactory.doCreateSR(WstxInputFactory.java:531)
at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:585)
at com.ctc.wstx.stax.WstxInputFactory.createSR(WstxInputFactory.java:610)
at com.ctc.wstx.stax.WstxInputFactory.createXMLStreamReader(WstxInputFactory.java:316)
at __redirected.__XMLInputFactory.createXMLStreamReader(__XMLInputFactory.java:139)
at org.apache.cxf.staxutils.StaxUtils.createXMLStreamReader(StaxUtils.java:1260)
at org.apache.cxf.interceptor.StaxInInterceptor.handleMessage(StaxInInterceptor.java:112)
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262)
- locked <0x00000007afc4d510> (a org.apache.cxf.phase.PhaseInterceptorChain)
at org.apache.cxf.endpoint.ClientImpl.onMessage(ClientImpl.java:800)
at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1694)
at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1530)
at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1438)
at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56)
at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:659)
at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62)
at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262)
- locked <0x0000000785e24a68> (a org.apache.cxf.phase.PhaseInterceptorChain)
at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:463)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:366)
at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:319)
at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96)
at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:134)
at com.sun.proxy.$Proxy60.test(Unknown Source)
at org.test.client.TestClient.run(TestClient.java:31)
-
3. Re: Re: JAX-WS handler creates high CPU load
ctomc Sep 16, 2014 9:07 AM (in response to markusdlugi)Hi,
that jstack report is from jboss as 7.x not from wildfly 8....
also JVM used looks quite old. can you try it on JDK7 u45 or newer?
-
4. Re: Re: Re: JAX-WS handler creates high CPU load
markusdlugi Sep 23, 2014 7:34 AM (in response to ctomc)Sorry for not responding earlier, I was being sick.
Anyway, I ran the test application again, this time on WildFly 8.1.0 and JDK 1.7.0_51. Full jstack report is attached, but it didn't change much - it's still the insertInterceptor method and KeepAliveCache handling that seems to create highest CPU demand. Any ideas?
-
jstack_wildfly.txt.zip 68.9 KB
-
-
5. Re: Re: Re: JAX-WS handler creates high CPU load
adityamcadu Sep 27, 2014 1:19 PM (in response to markusdlugi)I am facing the exact same issue with JBoss EAP 6.3 (based on JBoss 7.3 i guess). As soon as i remove the handler chain, the CPU usage goes down. This is affecting our production environment, and I will open a support case with RedHat (we have enterprise support). I hope you don't mind if I refer to this post and have them use the test scenario you have created.
-
6. Re: Re: Re: JAX-WS handler creates high CPU load
markusdlugi Sep 27, 2014 4:45 PM (in response to adityamcadu)Of course you can use my test application, I don't mind. I'd be really curious about the outcome though, so please post a small update if you find out something!
-
7. Re: JAX-WS handler creates high CPU load
adityamcadu Sep 28, 2014 1:39 PM (in response to markusdlugi)Opened a RedHat support case for the issue. Will keep the post updated once I get a response
-
8. Re: Re: Re: JAX-WS handler creates high CPU load
xxd Oct 9, 2014 11:00 AM (in response to markusdlugi)Hello, Markus,
I checked the thread dump you uploaded, why there were so many threads out there? And many of them were waiting (327) for a lock. You know, this kind of blocking is quite performance consuming...
-
9. Re: JAX-WS handler creates high CPU load
markusdlugi Oct 9, 2014 2:07 PM (in response to xxd)Hello,
Thanks for having a look. The reason for so many threads is that there are in fact 1000 client threads accessing the web services in my test application. I know that's a lot of threads, but that's part of the (already existing) application for which we are developing the SOAP handler, so I have no influence on that. Interestingly, the performance is perfectly fine when I don't use a SOAP handler (around 10% CPU usage), but drops drastically when adding the SOAP handler (nearly 100% CPU usage), although the SOAP handler does nothing really. I don't know why there is so much blocking happening - my personal assumption is that there might be some kind of livelock in the code invoking the handler. However, I don't know anything about that code, so I'd be really grateful if someone with more knowledge could have a look at it.
-
10. Re: Re: Re: JAX-WS handler creates high CPU load
xxd Oct 9, 2014 2:58 PM (in response to markusdlugi)Hello, Markus,
Thanks for the information. Here is just some my wild guessing, could you please rerun your test with this JVM option - "-Dhttp.maxConnections=500"?
Thanks a lot.