Hi Sergey. I compared 3.0.5 and 3.0.6 directly in GitHub and this commit caused the issue: https://github.com/apache/cxf/commit/6700967415f3e9bb1e62dcab1ea4e8660ed579b8 After removing it, compiling 3.0.6 locally and testing with it, results in a nice flat line in the class load/unload diagram. CPU usage dropped to 10% again and memory looks ok. So maybe you can figure out, what was the intention and how to avoid the loading. Maybe result caching of the already loaded classes is a solution? I'll do some additional tests though... Thanks Veit --
Gesendet: Freitag, 18. September 2015 um 14:36 Uhr Von: "Sergey Beryozkin" <sberyoz...@gmail.com> An: users@cxf.apache.org Betreff: Re: Aw: Re: Re: Re: NPE with message body writer during load Hi I'm not seeing anything immediately obvious from: https://issues.apache.org/jira/browse/CXF-6508?jql=project%20%3D%20CXF%20AND%20fixVersion%20%3D%203.0.6[https://issues.apache.org/jira/browse/CXF-6508?jql=project%20%3D%20CXF%20AND%20fixVersion%20%3D%203.0.6] There few changes done to the RS client code, but I'm not seeing what might've caused the extra class loading activity... Perhaps you can spot something from 3.0.6 changes ? Thanks, Sergey On 18/09/15 12:53, Veit Guna wrote: > Hi Sergey. > > Thanks for the quick feedback! > > We're using the apache httpclient wth 3.0.4 for some time now without a > problem (except the ThreadLocal NPE sometimes on startup of the load test). > It's performing really well - to be honest. > > We only changed the version in the POM for the tests of the various CXF > Versions (3.0.4 to 3.0.7-SNAPSHOT). > Nothing else of the configuration changed. So something changed with 3.0.6 > that introduces higher cpu-usage > and increased class loading. > > Yes, the thread is performing multiple invocations against his self created > client proxy instance. > Glad to hear, that this doesn't seem to be the problem. > > I haven't encountered any OOM yet. But I can perform another test that runs a > longer period. > I'm not sure what causes the constantly increasing class loading. I guess > that's also the reason why cpu-usage > and memory increases as well. With 3.0.4+3.0.5 class loading was a flat line > (as you can see on the images). > > Maybe I can take a heap dump and take a look at the allocated instances to > get a clue what is going on. > > Thanks > Veit > -- > > Gesendet: Freitag, 18. September 2015 um 13:15 Uhr > Von: "Sergey Beryozkin" <sberyoz...@gmail.com> > An: users@cxf.apache.org > Betreff: Re: Aw: Re: Re: NPE with message body writer during load > Hi Veit > On 18/09/15 12:01, Veit Guna wrote: >> Hi Sergey. >> >> It seems the "problems" came in with 3.0.6 - not with the ThreadLocal fix >> you did in 3.0.7-SNAPSHOT :). >> >> I'm using the CXF JAX-RS 2.0.1 client proxies using the apache httpclient >> network driver. I haven't activated >> the "thread-safe" option for the client. >> >> So you say that 3.0.4 worked well, because the clients closed themselves, >> but that isn't true anymore for CXF version > 3.0.4? > > I'm not asserting this is why you are observing a memory growth with > 3.0.7-SNAPSHOT. In fact, given that your case is the same thread doing > multiple invocations against the same proxy instance, it would not make > a difference because the proxy is alive all the time so no auto-closing > of the proxy resources happens. > >> That means I have to close the client proxy after _each request_? How would >> that look like? Cast to WebClient? This would >> introduce a lof of boilerplate code that I wanted to avoid using the client >> proxy :). >> > Yes, with proxy it would not look cool, WebClient.client(proxy).close(). > However, I think I can try making proxies Autocloseable so that in try() > it can look neater. It won't make a difference in this case though. > >> With "multiple invocations" you mean one thread performs multiple >> invocations on the same client proxy instance? Or multiple >> threads using the same client proxy instance? The latter case shouldn't >> happen in my usecase. >> > Yes, I was thinking may be it is the latter, so closing explicitly does > not help... > > Well, so I'm not sure what is causing some growth - no state -s > maintained, you do not get OOM though, right ? > > May be the difference is you switched from Java HttpUrlConnection to > HttpClient ? > > Cheers, Sergey >> Thanks >> Veit >> >> >> Gesendet: Freitag, 18. September 2015 um 11:15 Uhr >> Von: "Sergey Beryozkin" <sberyoz...@gmail.com> >> An: users@cxf.apache.org >> Betreff: Re: Aw: Re: NPE with message body writer during load >> Hi Veit >> >> Thanks for this thorough analysis. The fix I did does not introduce some >> state. >> >> Are you using 2.0 API ? I think in 3.0.4 WebClients (used internally in >> 2.0 impl) were closing themselves automatically in its finalize(). 2.0 >> API effectively requires a new instance per every target, so they are >> kept in a weak hash map - but auto-closing the weakly collected clients >> caused some side-effects in the production. >> >> So please make sure a Webclient or JAX-RS 2.0 client is closed between >> multiple invocations. >> >> If that does not help then I'd need a maven test project so that I can >> have a look at the code and experiment... >> >> Cheers, Sergey >> On 18/09/15 08:35, Veit Guna wrote: >>> Mkay. It seems attachments get filtered out. So I uploaded them here: >>> >>> http://s17.postimg.org/vy88qvbtr/cxf304.png[http://s17.postimg.org/vy88qvbtr/cxf304.png] >>> http://s17.postimg.org/kn5l2i4yn/cxf305.png[http://s17.postimg.org/kn5l2i4yn/cxf305.png][http://s17.postimg.org/kn5l2i4yn/cxf305.png[http://s17.postimg.org/kn5l2i4yn/cxf305.png]][http://s17.postimg.org/kn5l2i4yn/cxf305.png[http://s17.postimg.org/kn5l2i4yn/cxf305.png][http://s17.postimg.org/kn5l2i4yn/cxf305.png[http://s17.postimg.org/kn5l2i4yn/cxf305.png]]] >>> http://s17.postimg.org/qpd7szten/cxf306.png[http://s17.postimg.org/qpd7szten/cxf306.png][http://s17.postimg.org/qpd7szten/cxf306.png[http://s17.postimg.org/qpd7szten/cxf306.png]][http://s17.postimg.org/qpd7szten/cxf306.png[http://s17.postimg.org/qpd7szten/cxf306.png][http://s17.postimg.org/qpd7szten/cxf306.png[http://s17.postimg.org/qpd7szten/cxf306.png]]] >>> http://s17.postimg.org/sv7inhwv3/cxf307.png[http://s17.postimg.org/sv7inhwv3/cxf307.png][http://s17.postimg.org/sv7inhwv3/cxf307.png[http://s17.postimg.org/sv7inhwv3/cxf307.png]][http://s17.postimg.org/sv7inhwv3/cxf307.png[http://s17.postimg.org/sv7inhwv3/cxf307.png][http://s17.postimg.org/sv7inhwv3/cxf307.png[http://s17.postimg.org/sv7inhwv3/cxf307.png]]] >>> >>> >>> >>> >>> Gesendet: Freitag, 18. September 2015 um 09:04 Uhr >>> Von: "Veit Guna" <veit.g...@gmx.de> >>> An: users@cxf.apache.org >>> Betreff: Aw: Re: NPE with message body writer during load >>> Hi Sergey. >>> >>> Thanks for the fix. >>> >>> Now I had time to test the new 3.0.7-SNAPSHOT version. Although I couldn't >>> reproduce the error again, I encountered other >>> side effects. >>> >>> It seems that now many class load/unload operations are performed. With >>> 3.0.4, it was a flat line. Now it goes up and down between 5k and 8,5k >>> loads/unloads. >>> Also, it seems that more memory is needed and CPU usage went from ~10% to >>> ~20%-30%. >>> >>> So I performed our test with 2 runs, using versions 3.0.4 - 3.0.7-SNAPSHOT. >>> Please find attached the jvisualvm images for each version. >>> The test uses 50 threads and runs REST CRUD operations concurrently against >>> a server. I connected the jvisualvm to the testcase for >>> monitoring. >>> >>> >>> 3.0.4: 154s, 147s >>> - "original" >>> 3.0.5: 146s, 146s >>> - almost the same as 3.0.4 >>> 3.0.6: 164s, 165s >>> - classloading peaks >>> - higher cpu: 20%-30% >>> 3.0.7: 177s, 163s >>> - classloading peaks >>> - higher cpu: 20%-30% >>> >>> So it seems, that the load/unload came in with 3.0.6 which results in >>> ~20secs longer runtime of the test >>> and higher CPU usage. >>> >>> Any idea what causes this? >>> >>> I also tested the CXF client within our server application. Here class >>> loading is constantly increasing from 25k, up to 45k+ - without any >>> occuring unloading. >>> Performing a manual GC via jvisualvm does not have any effect on that. So I >>> guess it is leaking somewhere? >>> Test runtime went up from 115secs (3.0.4) to 470secs (3.0.7-SNAPSHOT). >>> >>> Thanks >>> Veit >>> >>> >>> >>> Gesendet: Dienstag, 15. September 2015 um 13:56 Uhr >>> Von: "Sergey Beryozkin" <sberyoz...@gmail.com> >>> An: users@cxf.apache.org >>> Betreff: Re: NPE with message body writer during load >>> This particular issue has been addressed: >>> >>> https://issues.apache.org/jira/browse/CXF-6593[https://issues.apache.org/jira/browse/CXF-6593][https://issues.apache.org/jira/browse/CXF-6593[https://issues.apache.org/jira/browse/CXF-6593]][https://issues.apache.org/jira/browse/CXF-6593[https://issues.apache.org/jira/browse/CXF-6593][https://issues.apache.org/jira/browse/CXF-6593[https://issues.apache.org/jira/browse/CXF-6593]]] >>> >>> However this is a short term solution and a more effective solution >>> would need to be done in a new trunk. >>> >>> The way the thread local proxies are managed is somewhat complex in CXF >>> JAX-RS - partially because the bulk of it was written many years back >>> and also because the same provider or resource instance can be shared >>> between multiple endpoints. We can investigate how the code can be >>> re-written when a new Java 8 trunk opens >>> >>> Cheers, Sergey >>> >>> >>> On 10/09/15 11:49, Sergey Beryozkin wrote: >>>> FYI, two more similar issues have been reported in the last couple of days. >>>> >>>> I start suspecting it might be a WeakHashMap optimization I did. In >>>> TomEE, the guys wanted to do a clean refresh of CXF (JAX-RS) module and >>>> the fact the bus was holding strong references to CXF context >>>> implementations such as UriInfoImpl, etc, was problematic (I'll need to >>>> ask Romain for few more details on that). So 'refresh' situations can >>>> possibly release the thread local proxies's content, just speculating >>>> but may be it is related >>>> >>>> So I'm on this issue now :-) >>>> >>>> Thanks, Sergey >>>> >>>> >>>> On 02/09/15 12:24, Sergey Beryozkin wrote: >>>>> Hi >>>>> >>>>> When CXF JAX-RS injects thread-local proxies into providers/resource >>>>> classes it keeps field and method proxy maps on the bus. I recall there >>>>> was a problem in one of the complex setups where there were many >>>>> endpoints with multiple Jackson instances (as opposed to a single >>>>> instance shared between the endpoints) where somehow the provider whose >>>>> thread local proxy was reset depending on the order of the provider >>>>> initialization. >>>>> >>>>> I vaguely recall the side-effect was caused by the fact there were >>>>> different bus instances involved too, this case is now tested in this >>>>> context: >>>>> >>>>> https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]]][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]]]][https://github.com/apache/cxf/blob/master/systest[https://github.com/apache/cxf/blob/master/systest] s /jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]]][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml][https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml[https://github.com/apache/cxf/blob/master/systests/jaxrs/src/test/resources/jaxrs_jackson_provider/WEB-INF/beans.xml]]]]] >>>>> >>>>> >>>>> >>>>> (one of the endpoints has a custom bus) >>>>> >>>>> Perhaps when a client is set up in a complex, possibly multi-threaded >>>>> environment some side-effects with setting tl proxies are possible. >>>>> Example if it is a single/default bus that is shared between all the >>>>> clients then if we have multiple threads then they affect the th maps >>>>> kept on the bus. >>>>> Please experiment with trying to have each client instance have its own >>>>> Bus ? (You can create a unique bus with BusFactory and then set it on >>>>> JAXRSClientFactoryBean before creating a proxy) - if that helps than you >>>>> can limit such a setup to a test env only unless the actual production >>>>> setup is also multi-threaded >>>>> >>>>> HTH, Sergey >>>>> >>>>> On 02/09/15 11:33, Veit Guna wrote: >>>>>> Hi. >>>>>> >>>>>> I'm using CXF 3.0.4 in client proxy mode, using my server REST >>>>>> interfaces. >>>>>> In addition I'm using the httpclient cxf module to workaround earlier >>>>>> problems with concurrency >>>>>> under load (as suggested by Sergey in a post some months ago here on >>>>>> the mailing list). >>>>>> >>>>>> For Multipart handling I'm using the jersey MultiPart JAX-RS >>>>>> MessageBodyWriter on the server >>>>>> as well as on the client. >>>>>> >>>>>> Under normal circumstances all goes well. But sometimes, especially on >>>>>> the startup-phase of the load test, >>>>>> the CXF client proxy dies with the exception below during a Multipart >>>>>> POST. Any clue what might cause this? >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log Caused by: >>>>>> org.apache.cxf.interceptor.Fault: No message body writer has been >>>>>> found for class org.glassfish.jersey.media.multipart.MultiPart, >>>>>> ContentType: multipart/mixed >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.ClientProxyImpl$BodyWriter.doWriteBody(ClientProxyImpl.java:814) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.AbstractClient$AbstractBodyWriter.handleMessage(AbstractClient.java:1042) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.AbstractClient.doRunInterceptorChain(AbstractClient.java:624) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.ClientProxyImpl.doChainedInvocation(ClientProxyImpl.java:674) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.ClientProxyImpl.invoke(ClientProxyImpl.java:224) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> com.sun.proxy.$Proxy484.create(Unknown Source) >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> my.class.doSomething(MyClass.java:383) >>>>>> 0f5ba696ffe4 fns-service.log ... 54 more >>>>>> 0f5ba696ffe4 fns-service.log Caused by: >>>>>> javax.ws.rs.ProcessingException: No message body writer has been found >>>>>> for class org.glassfish.jersey.media.multipart.MultiPart, ContentType: >>>>>> multipart/mixed >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.AbstractClient.reportMessageHandlerProblem(AbstractClient.java:741) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.AbstractClient.writeBody(AbstractClient.java:470) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.ClientProxyImpl$BodyWriter.doWriteBody(ClientProxyImpl.java:804) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log ... 62 more >>>>>> 0f5ba696ffe4 fns-service.log Caused by: java.lang.NullPointerException >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.impl.tl.ThreadLocalProviders.getMessageBodyWriter(ThreadLocalProviders.java:46) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.glassfish.jersey.media.multipart.internal.MultiPartWriter.writeTo(MultiPartWriter.java:222) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.glassfish.jersey.media.multipart.internal.MultiPartWriter.writeTo(MultiPartWriter.java:79) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.utils.JAXRSUtils.writeMessageBody(JAXRSUtils.java:1379) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log at >>>>>> org.apache.cxf.jaxrs.client.AbstractClient.writeBody(AbstractClient.java:456) >>>>>> >>>>>> >>>>>> 0f5ba696ffe4 fns-service.log ... 63 more >>>>>> >>>>> >>>>> >>>> >>>> >>> >>> >>> -- >>> Sergey Beryozkin >>> >>> Talend Community Coders >>> http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]]]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]]]]] >>> >> >> >> -- >> Sergey Beryozkin >> >> Talend Community Coders >> http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]][http://coders.talend.com/[http://coders.talend.com/][http://coders.talend.com/[http://coders.talend.com/]]] >> > >