Re: NPE with message body writer during load

Sergey Beryozkin Fri, 18 Sep 2015 09:23:59 -0700

Hi Veit

and may be also give us a test project if tracing won't help ? Dan had agood point about why the loader is not caching. Is proxy created byCGLIB by any chance ?


Thanks, Sergey



On 18/09/15 17:15, Daniel Kulp wrote:


Can you put that code back in but then add a println or log or something in the 
two catch statements that are returning null and see if it’s now triggering 
those clauses?   If it returns false, we have to create a new class loader for 
the proxy class which could possibly be the issue.

If there is an issue and it’s returning false there, you might be able to see 
which class is causing the issue and make sure that’s available in your 
application thus allowing the “return true” to trigger.

Likely there should be  a LOG.fine(…) there anyway to help diagnose this.

Dan

On Sep 18, 2015, at 11:16 AM, Veit Guna <[email protected]> wrote:

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" <[email protected]>
An: [email protected]
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" <[email protected]>
An: [email protected]
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" <[email protected]>
An: [email protected]
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" <[email protected]>
An: [email protected]
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" <[email protected]>
An: [email protected]
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/syste

s
ts/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-

I
NF/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/]]]



--
Sergey Beryozkin

Talend Community Coders
http://coders.talend.com/

Re: NPE with message body writer during load

Reply via email to